This job view page is being replaced by Spyglass soon. Check out the new job view.
ResultFAILURE
Tests 0 failed / 0 succeeded
Started2022-06-06 18:01
Elapsed8m6s
Revisiona1f073a1996accdcd1630d6aa257208a8c239c14

No Test Failures!


Error lines from build-log.txt

... skipping 128 lines ...
=== RUN   TestValidateConfigWithNoNetPermissionParams
{"level":"info","time":"2022-06-06T18:04:24.337847081Z","caller":"config/config.go:364","msg":"No Net Permissions given in Config. Using default permissions."}
--- PASS: TestValidateConfigWithNoNetPermissionParams (0.01s)
=== RUN   TestValidateConfigWithMultipleNetPermissionParams
--- PASS: TestValidateConfigWithMultipleNetPermissionParams (0.01s)
=== RUN   TestValidateConfigWithInvalidPermissions
{"level":"error","time":"2022-06-06T18:04:24.349160978Z","caller":"config/config.go:375","msg":"Invalid value WRITE_ONLY for Permissions under NetPermission Config A","stacktrace":"sigs.k8s.io/vsphere-csi-driver/v2/pkg/common/config.validateConfig\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/common/config/config.go:375\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/common/config.TestValidateConfigWithInvalidPermissions\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/common/config/config_test.go:144\ntesting.tRunner\n\t/usr/local/go/src/testing/testing.go:1439"}
--- PASS: TestValidateConfigWithInvalidPermissions (0.00s)
=== RUN   TestValidateConfigWithInvalidClusterId
{"level":"error","time":"2022-06-06T18:04:24.349304912Z","caller":"config/config.go:316","msg":"cluster id must not exceed 64 characters","stacktrace":"sigs.k8s.io/vsphere-csi-driver/v2/pkg/common/config.validateConfig\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/common/config/config.go:316\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/common/config.TestValidateConfigWithInvalidClusterId\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/common/config/config_test.go:156\ntesting.tRunner\n\t/usr/local/go/src/testing/testing.go:1439"}
--- PASS: TestValidateConfigWithInvalidClusterId (0.00s)
=== RUN   TestSnapshotConfigWhenMaxUnspecified
{"level":"info","time":"2022-06-06T18:04:24.351331159Z","caller":"config/config.go:364","msg":"No Net Permissions given in Config. Using default permissions."}
--- PASS: TestSnapshotConfigWhenMaxUnspecified (0.00s)
=== RUN   TestSnapshotConfigWhenMaxSpecifiedAsEnv
{"level":"info","time":"2022-06-06T18:04:24.35251844Z","caller":"config/config.go:364","msg":"No Net Permissions given in Config. Using default permissions."}
--- PASS: TestSnapshotConfigWhenMaxSpecifiedAsEnv (0.00s)
PASS
ok  	sigs.k8s.io/vsphere-csi-driver/v2/pkg/common/config	0.044s
=== RUN   TestQuerySnapshotsUtil
{"level":"error","time":"2022-06-06T18:04:49.919689769Z","caller":"config/config.go:311","msg":"no Virtual Center hosts defined","stacktrace":"sigs.k8s.io/vsphere-csi-driver/v2/pkg/common/config.validateConfig\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/common/config/config.go:311\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/common/config.FromEnv\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/common/config/config.go:295\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/common/utils.configFromEnvOrSim\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/common/utils/utils_test.go:105\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/common/utils.getCommonUtilsTest.func1\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/common/utils/utils_test.go:115\nsync.(*Once).doSlow\n\t/usr/local/go/src/sync/once.go:68\nsync.(*Once).Do\n\t/usr/local/go/src/sync/once.go:59\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/common/utils.getCommonUtilsTest\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/common/utils/utils_test.go:112\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/common/utils.TestQuerySnapshotsUtil\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/common/utils/utils_test.go:146\ntesting.tRunner\n\t/usr/local/go/src/testing/testing.go:1439"}
{"level":"info","time":"2022-06-06T18:04:50.323617722Z","caller":"vsphere/utils.go:189","msg":"Defaulting timeout for vCenter Client to 5 minutes"}
{"level":"info","time":"2022-06-06T18:04:50.323725706Z","caller":"vsphere/virtualcentermanager.go:74","msg":"Initializing defaultVirtualCenterManager..."}
{"level":"info","time":"2022-06-06T18:04:50.323750985Z","caller":"vsphere/virtualcentermanager.go:76","msg":"Successfully initialized defaultVirtualCenterManager"}
{"level":"info","time":"2022-06-06T18:04:50.323837883Z","caller":"vsphere/virtualcentermanager.go:122","msg":"Successfully registered VC \"127.0.0.1\""}
{"level":"info","time":"2022-06-06T18:04:50.332402954Z","caller":"vsphere/virtualcenter.go:183","msg":"New session ID for 'user' = 9e251196-a8b1-4796-bace-72fd6812f9fb"}
{"level":"info","time":"2022-06-06T18:04:50.337146823Z","caller":"volume/manager.go:175","msg":"Initializing new defaultManager..."}
... skipping 6 lines ...
    utils_test.go:161: Snapshots: 
--- PASS: TestQuerySnapshotsUtil (0.43s)
=== RUN   TestGetDatastoreRefByURLFromGivenDatastoreList
=== RUN   TestGetDatastoreRefByURLFromGivenDatastoreList/CompatibleDatastoreFound
{"level":"info","time":"2022-06-06T18:04:50.363602625Z","caller":"utils/utils.go:269","msg":"compatible datastore found, dsURL = \"/tmp/govcsim-DC0-LocalDS_2-4007563605\", dsRef = Datastore:/tmp/govcsim-DC0-LocalDS_2-4007563605@group-5"}
=== RUN   TestGetDatastoreRefByURLFromGivenDatastoreList/FailToFindGivenDatastoreInCompatibleList
{"level":"error","time":"2022-06-06T18:04:50.372155552Z","caller":"utils/utils.go:274","msg":"failed to find datastore with URL \"/tmp/govcsim-DC0-LocalDS_2-4007563605\" from the input datastore list, [Datastore:/tmp/govcsim-DC0-LocalDS_0-1959114744@group-5 Datastore:/tmp/govcsim-DC0-LocalDS_1-121134927@group-5]","stacktrace":"sigs.k8s.io/vsphere-csi-driver/v2/pkg/common/utils.GetDatastoreRefByURLFromGivenDatastoreList\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/common/utils/utils.go:274\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/common/utils.TestGetDatastoreRefByURLFromGivenDatastoreList.func1\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/common/utils/utils_test.go:252\ntesting.tRunner\n\t/usr/local/go/src/testing/testing.go:1439"}
=== RUN   TestGetDatastoreRefByURLFromGivenDatastoreList/FailToFindGivenDatastoreInVC
{"level":"error","time":"2022-06-06T18:04:50.382937607Z","caller":"vsphere/datacenter.go:82","msg":"couldn't find Datastore given URL \"an-invalid-datastore-url\"","stacktrace":"sigs.k8s.io/vsphere-csi-driver/v2/pkg/common/cns-lib/vsphere.(*Datacenter).GetDatastoreInfoByURL\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/common/cns-lib/vsphere/datacenter.go:82\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/common/utils.GetDatastoreRefByURLFromGivenDatastoreList\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/common/utils/utils.go:251\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/common/utils.TestGetDatastoreRefByURLFromGivenDatastoreList.func1\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/common/utils/utils_test.go:252\ntesting.tRunner\n\t/usr/local/go/src/testing/testing.go:1439"}
{"level":"error","time":"2022-06-06T18:04:50.383135404Z","caller":"utils/utils.go:253","msg":"failed to find datastore with URL \"an-invalid-datastore-url\" in datacenter \"/DC0\" from VC \"127.0.0.1\", Error: couldn't find Datastore given URL \"an-invalid-datastore-url\"","stacktrace":"sigs.k8s.io/vsphere-csi-driver/v2/pkg/common/utils.GetDatastoreRefByURLFromGivenDatastoreList\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/common/utils/utils.go:253\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/common/utils.TestGetDatastoreRefByURLFromGivenDatastoreList.func1\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/common/utils/utils_test.go:252\ntesting.tRunner\n\t/usr/local/go/src/testing/testing.go:1439"}
{"level":"error","time":"2022-06-06T18:04:50.383209386Z","caller":"utils/utils.go:263","msg":"failed to find datastore with URL \"an-invalid-datastore-url\" in VC \"127.0.0.1\"","stacktrace":"sigs.k8s.io/vsphere-csi-driver/v2/pkg/common/utils.GetDatastoreRefByURLFromGivenDatastoreList\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/common/utils/utils.go:263\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/common/utils.TestGetDatastoreRefByURLFromGivenDatastoreList.func1\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/common/utils/utils_test.go:252\ntesting.tRunner\n\t/usr/local/go/src/testing/testing.go:1439"}
=== RUN   TestGetDatastoreRefByURLFromGivenDatastoreList/EmptyDatastoreURLFromInput
{"level":"error","time":"2022-06-06T18:04:50.391959205Z","caller":"vsphere/datacenter.go:82","msg":"couldn't find Datastore given URL \"\"","stacktrace":"sigs.k8s.io/vsphere-csi-driver/v2/pkg/common/cns-lib/vsphere.(*Datacenter).GetDatastoreInfoByURL\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/common/cns-lib/vsphere/datacenter.go:82\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/common/utils.GetDatastoreRefByURLFromGivenDatastoreList\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/common/utils/utils.go:251\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/common/utils.TestGetDatastoreRefByURLFromGivenDatastoreList.func1\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/common/utils/utils_test.go:252\ntesting.tRunner\n\t/usr/local/go/src/testing/testing.go:1439"}
{"level":"error","time":"2022-06-06T18:04:50.392136726Z","caller":"utils/utils.go:253","msg":"failed to find datastore with URL \"\" in datacenter \"/DC0\" from VC \"127.0.0.1\", Error: couldn't find Datastore given URL \"\"","stacktrace":"sigs.k8s.io/vsphere-csi-driver/v2/pkg/common/utils.GetDatastoreRefByURLFromGivenDatastoreList\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/common/utils/utils.go:253\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/common/utils.TestGetDatastoreRefByURLFromGivenDatastoreList.func1\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/common/utils/utils_test.go:252\ntesting.tRunner\n\t/usr/local/go/src/testing/testing.go:1439"}
{"level":"error","time":"2022-06-06T18:04:50.392195145Z","caller":"utils/utils.go:263","msg":"failed to find datastore with URL \"\" in VC \"127.0.0.1\"","stacktrace":"sigs.k8s.io/vsphere-csi-driver/v2/pkg/common/utils.GetDatastoreRefByURLFromGivenDatastoreList\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/common/utils/utils.go:263\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/common/utils.TestGetDatastoreRefByURLFromGivenDatastoreList.func1\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/common/utils/utils_test.go:252\ntesting.tRunner\n\t/usr/local/go/src/testing/testing.go:1439"}
--- PASS: TestGetDatastoreRefByURLFromGivenDatastoreList (0.04s)
    --- PASS: TestGetDatastoreRefByURLFromGivenDatastoreList/CompatibleDatastoreFound (0.02s)
    --- PASS: TestGetDatastoreRefByURLFromGivenDatastoreList/FailToFindGivenDatastoreInCompatibleList (0.01s)
    --- PASS: TestGetDatastoreRefByURLFromGivenDatastoreList/FailToFindGivenDatastoreInVC (0.01s)
    --- PASS: TestGetDatastoreRefByURLFromGivenDatastoreList/EmptyDatastoreURLFromInput (0.01s)
PASS
ok  	sigs.k8s.io/vsphere-csi-driver/v2/pkg/common/utils	0.560s
=== RUN   TestUseVslmAPIsFuncForVC67Update3l
--- PASS: TestUseVslmAPIsFuncForVC67Update3l (0.00s)
=== RUN   TestUseVslmAPIsFuncForVC67Update3a
{"level":"error","time":"2022-06-06T18:04:50.9111466Z","caller":"common/common_controller_helper.go:197","msg":"Found vCenter version :\"6.7.3\". The minimum version for CSI migration is vCenter Server 6.7 Update 3l","stacktrace":"sigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/common.UseVslmAPIs\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/common/common_controller_helper.go:197\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/common.TestUseVslmAPIsFuncForVC67Update3a\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/common/common_controller_helper_test.go:77\ntesting.tRunner\n\t/usr/local/go/src/testing/testing.go:1439"}
    common_controller_helper_test.go:81: expected err received. err: Found vCenter version :"6.7.3". The minimum version for CSI migration is vCenter Server 6.7 Update 3l
--- PASS: TestUseVslmAPIsFuncForVC67Update3a (0.00s)
=== RUN   TestUseVslmAPIsFuncForVC6dot6
--- PASS: TestUseVslmAPIsFuncForVC6dot6 (0.00s)
=== RUN   TestUseVslmAPIsFuncForVC7
--- PASS: TestUseVslmAPIsFuncForVC7 (0.00s)
... skipping 40 lines ...
    --- PASS: TestParseCSISnapshotID/EmptyCSISnapshotID (0.00s)
    --- PASS: TestParseCSISnapshotID/UnexpectedFormattedCSISnapshotID (0.00s)
=== RUN   TestQueryVolumeSnapshotsByVolumeIDWithQuerySnapshotsCnsVolumeNotFoundFault
{"level":"warn","time":"2022-06-06T18:04:50.917101657Z","caller":"common/vsphereutil.go:910","msg":"volume dummy-id was not found during QuerySnapshots, ignore volume.."}
--- PASS: TestQueryVolumeSnapshotsByVolumeIDWithQuerySnapshotsCnsVolumeNotFoundFault (0.00s)
=== RUN   TestQueryVolumeSnapshotsByVolumeIDWithQuerySnapshotsUnexpectedFault
{"level":"error","time":"2022-06-06T18:04:50.919188429Z","caller":"common/vsphereutil.go:913","msg":"unexpected fault &{RuntimeFault:{MethodFault:{FaultCause:<nil> FaultMessage:[]}} InvalidProperty:unexpected} received in QuerySnapshots result: {DynamicData:{} Snapshot:{DynamicData:{} SnapshotId:{DynamicData:{} Id:} VolumeId:{DynamicData:{} Id:} Description: CreateTime:0001-01-01 00:00:00 +0000 UTC} Error:0xc000526060} for volume: dummy-id","stacktrace":"sigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/common.QueryVolumeSnapshotsByVolumeID\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/common/vsphereutil.go:913\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/common.TestQueryVolumeSnapshotsByVolumeIDWithQuerySnapshotsUnexpectedFault\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/common/vsphereutil_test.go:66\ntesting.tRunner\n\t/usr/local/go/src/testing/testing.go:1439"}
--- PASS: TestQueryVolumeSnapshotsByVolumeIDWithQuerySnapshotsUnexpectedFault (0.00s)
=== RUN   TestQueryVolumeSnapshotWithQuerySnapshotsCnsSnapshotNotFoundFault
{"level":"error","time":"2022-06-06T18:04:50.919842264Z","caller":"common/vsphereutil.go:769","msg":"snapshot-id: dummy-snap-id not found for volume-id: dummy-id during QuerySnapshots, err: {CnsFault:{BaseMethodFault:<nil> Reason:} VolumeId:{DynamicData:{} Id:dummy-id} SnapshotId:{DynamicData:{} Id:dummy-snap-id}}","stacktrace":"sigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/common.QueryVolumeSnapshot\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/common/vsphereutil.go:769\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/common.TestQueryVolumeSnapshotWithQuerySnapshotsCnsSnapshotNotFoundFault\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/common/vsphereutil_test.go:99\ntesting.tRunner\n\t/usr/local/go/src/testing/testing.go:1439"}
--- PASS: TestQueryVolumeSnapshotWithQuerySnapshotsCnsSnapshotNotFoundFault (0.00s)
=== RUN   TestQueryVolumeSnapshotWithQuerySnapshotsUnexpectedFault
{"level":"error","time":"2022-06-06T18:04:50.920319434Z","caller":"common/vsphereutil.go:772","msg":"unexpected error received when retrieving snapshot info for volume-id: dummy-id snapshot-id: dummy-snap-id err: &{RuntimeFault:{MethodFault:{FaultCause:<nil> FaultMessage:[]}} InvalidProperty:unexpected}","stacktrace":"sigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/common.QueryVolumeSnapshot\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/common/vsphereutil.go:772\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/common.TestQueryVolumeSnapshotWithQuerySnapshotsUnexpectedFault\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/common/vsphereutil_test.go:126\ntesting.tRunner\n\t/usr/local/go/src/testing/testing.go:1439"}
--- PASS: TestQueryVolumeSnapshotWithQuerySnapshotsUnexpectedFault (0.00s)
=== RUN   TestQueryAllVolumeSnapshotsWithQuerySnapshotsUnexpectedFault
{"level":"error","time":"2022-06-06T18:04:50.920725473Z","caller":"common/vsphereutil.go:836","msg":"faults are not expected when invoking QuerySnapshots without volume-id and snapshot-id, fault: &{RuntimeFault:{MethodFault:{FaultCause:<nil> FaultMessage:[]}} InvalidProperty:unexpected}","stacktrace":"sigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/common.QueryAllVolumeSnapshots\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/common/vsphereutil.go:836\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/common.TestQueryAllVolumeSnapshotsWithQuerySnapshotsUnexpectedFault\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/common/vsphereutil_test.go:151\ntesting.tRunner\n\t/usr/local/go/src/testing/testing.go:1439"}
--- PASS: TestQueryAllVolumeSnapshotsWithQuerySnapshotsUnexpectedFault (0.00s)
PASS
ok  	sigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/common	0.098s
=== RUN   TestIsFSSEnabledInGcWithSync
{"level":"info","time":"2022-06-06T18:04:53.243112026Z","caller":"k8sorchestrator/k8sorchestrator.go:973","msg":"volume-health feature state set to false in internal-feature-states.csi.vsphere.vmware.com ConfigMap"}
--- PASS: TestIsFSSEnabledInGcWithSync (0.00s)
=== RUN   TestIsFSSEnabledInGcWithoutSync
{"level":"info","time":"2022-06-06T18:04:53.243398603Z","caller":"k8sorchestrator/k8sorchestrator.go:973","msg":"volume-extend feature state set to false in internal-feature-states.csi.vsphere.vmware.com ConfigMap"}
{"level":"info","time":"2022-06-06T18:04:53.250826215Z","caller":"k8sorchestrator/k8sorchestrator.go:992","msg":"volume-health feature state set to false in csi-feature-states ConfigMap"}
--- PASS: TestIsFSSEnabledInGcWithoutSync (0.01s)
=== RUN   TestIsFSSEnabledInGcWrongValues
{"level":"error","time":"2022-06-06T18:04:53.25228783Z","caller":"k8sorchestrator/k8sorchestrator.go:967","msg":"Error while converting volume-extend feature state value: false to boolean. Setting the feature state to false","stacktrace":"sigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/common/commonco/k8sorchestrator.(*K8sOrchestrator).IsFSSEnabled\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/common/commonco/k8sorchestrator/k8sorchestrator.go:967\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/common/commonco/k8sorchestrator.TestIsFSSEnabledInGcWrongValues\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/common/commonco/k8sorchestrator/k8sorchestrator_test.go:143\ntesting.tRunner\n\t/usr/local/go/src/testing/testing.go:1439"}
--- PASS: TestIsFSSEnabledInGcWrongValues (0.00s)
=== RUN   TestIsFSSEnabledInSV
{"level":"error","time":"2022-06-06T18:04:53.25339699Z","caller":"k8sorchestrator/k8sorchestrator.go:953","msg":"Error while converting csi-migration feature state value: false to boolean. Setting the feature state to false","stacktrace":"sigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/common/commonco/k8sorchestrator.(*K8sOrchestrator).IsFSSEnabled\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/common/commonco/k8sorchestrator/k8sorchestrator.go:953\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/common/commonco/k8sorchestrator.TestIsFSSEnabledInSV\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/common/commonco/k8sorchestrator/k8sorchestrator_test.go:179\ntesting.tRunner\n\t/usr/local/go/src/testing/testing.go:1439"}
--- PASS: TestIsFSSEnabledInSV (0.00s)
=== RUN   TestIsFSSEnabledInVanilla
{"level":"error","time":"2022-06-06T18:04:53.257246323Z","caller":"k8sorchestrator/k8sorchestrator.go:939","msg":"Error while converting volume-health feature state value: false to boolean. Setting the feature state to false","stacktrace":"sigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/common/commonco/k8sorchestrator.(*K8sOrchestrator).IsFSSEnabled\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/common/commonco/k8sorchestrator/k8sorchestrator.go:939\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/common/commonco/k8sorchestrator.TestIsFSSEnabledInVanilla\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/common/commonco/k8sorchestrator/k8sorchestrator_test.go:217\ntesting.tRunner\n\t/usr/local/go/src/testing/testing.go:1439"}
--- PASS: TestIsFSSEnabledInVanilla (0.00s)
=== RUN   TestIsFSSEnabledWithWrongClusterFlavor
--- PASS: TestIsFSSEnabledWithWrongClusterFlavor (0.00s)
=== RUN   TestGetNodesForVolumes
--- PASS: TestGetNodesForVolumes (0.00s)
PASS
ok  	sigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/common/commonco/k8sorchestrator	0.170s
=== RUN   TestLogNewError
{"level":"error","time":"2022-06-06T18:04:45.004673369Z","caller":"logger/logger_test.go:27","msg":"Error Test","stacktrace":"sigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/logger.TestLogNewError\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/logger/logger_test.go:27\ntesting.tRunner\n\t/usr/local/go/src/testing/testing.go:1439"}
--- PASS: TestLogNewError (0.00s)
=== RUN   TestLogNewErrorf
{"level":"error","time":"2022-06-06T18:04:45.005005935Z","caller":"logger/logger_test.go:35","msg":"Error Test","stacktrace":"sigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/logger.TestLogNewErrorf\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/logger/logger_test.go:35\ntesting.tRunner\n\t/usr/local/go/src/testing/testing.go:1439"}
--- PASS: TestLogNewErrorf (0.00s)
=== RUN   TestLogNewErrorCode
{"level":"error","time":"2022-06-06T18:04:45.005168943Z","caller":"logger/logger_test.go:43","msg":"Error Test","stacktrace":"sigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/logger.TestLogNewErrorCode\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/logger/logger_test.go:43\ntesting.tRunner\n\t/usr/local/go/src/testing/testing.go:1439"}
--- PASS: TestLogNewErrorCode (0.00s)
=== RUN   TestLogNewErrorCodef
{"level":"error","time":"2022-06-06T18:04:45.005276931Z","caller":"logger/logger_test.go:51","msg":"Error Test","stacktrace":"sigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/logger.TestLogNewErrorCodef\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/logger/logger_test.go:51\ntesting.tRunner\n\t/usr/local/go/src/testing/testing.go:1439"}
--- PASS: TestLogNewErrorCodef (0.00s)
PASS
ok  	sigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/logger	0.035s
=== RUN   TestUnescape
=== RUN   TestUnescape/0
=== PAUSE TestUnescape/0
... skipping 4 lines ...
=== RUN   TestUnescape/3
=== PAUSE TestUnescape/3
=== CONT  TestUnescape/0
=== CONT  TestUnescape/3
=== CONT  TestUnescape/2
=== CONT  TestUnescape/1
{"level":"info","time":"2022-06-06T18:04:51.765235625Z","caller":"osutils/linux_os_utils.go:1053","msg":"Error parsing mount \"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/foo\\\\0bc\": invalid syntax"}
{"level":"info","time":"2022-06-06T18:04:51.784454566Z","caller":"osutils/linux_os_utils.go:1053","msg":"Error parsing mount \"/var/lib/kubelet/plugins/kubernetes.io/csi/pv/foo\\\\04\": invalid syntax"}
--- PASS: TestUnescape (0.00s)
    --- PASS: TestUnescape/3 (0.00s)
    --- PASS: TestUnescape/2 (0.02s)
    --- PASS: TestUnescape/1 (0.02s)
    --- PASS: TestUnescape/0 (0.02s)
=== RUN   TestGetDiskPath
... skipping 6 lines ...
--- PASS: TestGetDiskPath (0.00s)
    --- PASS: TestGetDiskPath/#00 (0.00s)
    --- PASS: TestGetDiskPath/#01 (0.00s)
PASS
ok  	sigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/osutils	0.169s
=== RUN   TestCreateVolumeWithStoragePolicy
{"level":"error","time":"2022-06-06T18:04:57.720348675Z","caller":"config/config.go:311","msg":"no Virtual Center hosts defined","stacktrace":"sigs.k8s.io/vsphere-csi-driver/v2/pkg/common/config.validateConfig\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/common/config/config.go:311\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/common/config.FromEnv\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/common/config/config.go:295\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/vanilla.configFromEnvOrSim\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/vanilla/controller_test.go:167\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/vanilla.getControllerTest.func1\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/vanilla/controller_test.go:312\nsync.(*Once).doSlow\n\t/usr/local/go/src/sync/once.go:68\nsync.(*Once).Do\n\t/usr/local/go/src/sync/once.go:59\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/vanilla.getControllerTest\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/vanilla/controller_test.go:309\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/vanilla.TestCreateVolumeWithStoragePolicy\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/vanilla/controller_test.go:388\ntesting.tRunner\n\t/usr/local/go/src/testing/testing.go:1439"}
{"level":"info","time":"2022-06-06T18:04:58.104915964Z","caller":"vsphere/utils.go:189","msg":"Defaulting timeout for vCenter Client to 5 minutes"}
{"level":"info","time":"2022-06-06T18:04:58.105158546Z","caller":"vsphere/virtualcentermanager.go:74","msg":"Initializing defaultVirtualCenterManager..."}
{"level":"info","time":"2022-06-06T18:04:58.105291958Z","caller":"vsphere/virtualcentermanager.go:76","msg":"Successfully initialized defaultVirtualCenterManager"}
{"level":"info","time":"2022-06-06T18:04:58.105394241Z","caller":"vsphere/virtualcentermanager.go:122","msg":"Successfully registered VC \"127.0.0.1\""}
{"level":"info","time":"2022-06-06T18:04:58.115868994Z","caller":"vsphere/virtualcenter.go:183","msg":"New session ID for 'user' = b4e95d33-3b3e-4603-adf1-246c9c3a4a51"}
{"level":"info","time":"2022-06-06T18:04:58.116769989Z","caller":"volume/manager.go:175","msg":"Initializing new defaultManager..."}
... skipping 77 lines ...
{"level":"info","time":"2022-06-06T18:04:58.224878639Z","caller":"volume/manager.go:1039","msg":"DeleteVolume: Volume deleted successfully. volumeID: \"7157fbf4-adf2-496a-9297-5f0bc014c19f\", opId: \"\"","TraceId":"82750738-4739-4127-9dda-d5032c349a71"}
{"level":"info","time":"2022-06-06T18:04:58.224902861Z","caller":"vanilla/controller.go:979","msg":"Volume \"7157fbf4-adf2-496a-9297-5f0bc014c19f\" deleted successfully.","TraceId":"82750738-4739-4127-9dda-d5032c349a71"}
--- PASS: TestExtendVolume (0.04s)
=== RUN   TestMigratedExtendVolume
    controller_test.go:695: ControllerExpandVolume will be called with req +{[vsanDatastore] 08281a5f-a21d-1eff-62d6-02009d0f19a1/004dbb1694f14e3598abef852b113e3b.vmdk required_bytes:1024  map[] <nil> {} [] 0}
{"level":"info","time":"2022-06-06T18:04:58.225981987Z","caller":"vanilla/controller.go:1246","msg":"ControllerExpandVolume: called with args {VolumeId:[vsanDatastore] 08281a5f-a21d-1eff-62d6-02009d0f19a1/004dbb1694f14e3598abef852b113e3b.vmdk CapacityRange:required_bytes:1024  Secrets:map[] VolumeCapability:<nil> XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}","TraceId":"5c8fc7c8-6d93-4fd4-a35b-3b6310e4e756"}
{"level":"error","time":"2022-06-06T18:04:58.226040027Z","caller":"vanilla/controller.go:1256","msg":"cannot expand migrated vSphere volume. :\"[vsanDatastore] 08281a5f-a21d-1eff-62d6-02009d0f19a1/004dbb1694f14e3598abef852b113e3b.vmdk\"","TraceId":"5c8fc7c8-6d93-4fd4-a35b-3b6310e4e756","stacktrace":"sigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/vanilla.(*controller).ControllerExpandVolume.func1\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/vanilla/controller.go:1256\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/vanilla.(*controller).ControllerExpandVolume\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/vanilla/controller.go:1329\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/vanilla.TestMigratedExtendVolume\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/vanilla/controller_test.go:696\ntesting.tRunner\n\t/usr/local/go/src/testing/testing.go:1439"}
    controller_test.go:698: Expected error received. migrated volume with VMDK path can not be expanded
--- PASS: TestMigratedExtendVolume (0.00s)
=== RUN   TestCompleteControllerFlow
{"level":"info","time":"2022-06-06T18:04:58.227079634Z","caller":"vanilla/controller.go:828","msg":"CreateVolume: called with args {Name:test-pvc-10ddd54a-895a-4251-b97a-d899b6daba2a CapacityRange:required_bytes:1073741824  VolumeCapabilities:[access_mode:<mode:SINGLE_NODE_WRITER > ] Parameters:map[] Secrets:map[] VolumeContentSource:<nil> AccessibilityRequirements:<nil> XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}","TraceId":"0331ce84-f2aa-4756-94ee-e7efa34914ce"}
{"level":"info","time":"2022-06-06T18:04:58.240814116Z","caller":"volume/manager.go:410","msg":"CreateVolume: VolumeName: \"test-pvc-10ddd54a-895a-4251-b97a-d899b6daba2a\", opId: \"\"","TraceId":"0331ce84-f2aa-4756-94ee-e7efa34914ce"}
{"level":"info","time":"2022-06-06T18:04:58.241655412Z","caller":"volume/util.go:322","msg":"Volume created successfully. VolumeName: \"test-pvc-10ddd54a-895a-4251-b97a-d899b6daba2a\", volumeID: \"278faa3d-0f39-43b2-9ddb-ffed3ca13e4c\"","TraceId":"0331ce84-f2aa-4756-94ee-e7efa34914ce"}
{"level":"info","time":"2022-06-06T18:04:58.241745988Z","caller":"vanilla/controller.go:863","msg":"Volume created successfully. Volume Handle: \"278faa3d-0f39-43b2-9ddb-ffed3ca13e4c\", PV Name: \"test-pvc-10ddd54a-895a-4251-b97a-d899b6daba2a\"","TraceId":"0331ce84-f2aa-4756-94ee-e7efa34914ce"}
... skipping 38 lines ...
{"level":"info","time":"2022-06-06T18:04:58.287465543Z","caller":"utils/utils.go:118","msg":"invoking QuerySnapshots in iteration: 1 with offset: 0 and limit: 128, current total results: 0","TraceId":"27b1a5cb-320b-46a0-b5af-d0238ac0c79b"}
{"level":"info","time":"2022-06-06T18:04:58.291219672Z","caller":"utils/utils.go:150","msg":"setting max iteration to 0 for total records count: 0","TraceId":"27b1a5cb-320b-46a0-b5af-d0238ac0c79b"}
{"level":"info","time":"2022-06-06T18:04:58.291281199Z","caller":"utils/utils.go:170","msg":"0 more snapshots to be queried","TraceId":"27b1a5cb-320b-46a0-b5af-d0238ac0c79b"}
{"level":"info","time":"2022-06-06T18:04:58.291305121Z","caller":"utils/utils.go:173","msg":"QuerySnapshots retrieved all records (0) for the SnapshotQuerySpec: {DynamicData:{} VolumeId:{DynamicData:{} Id:0e21840d-285c-417a-b08d-ff66a23d920a} SnapshotId:<nil>} in 1 iterations","TraceId":"27b1a5cb-320b-46a0-b5af-d0238ac0c79b"}
{"level":"info","time":"2022-06-06T18:04:58.291337958Z","caller":"utils/utils.go:208","msg":"Invoking QueryAllVolumeUtil with Filter: {DynamicData:{} VolumeIds:[{DynamicData:{} Id:0e21840d-285c-417a-b08d-ff66a23d920a}] Names:[] ContainerClusterIds:[] StoragePolicyId: Datastores:[] Labels:[] ComplianceStatus: DatastoreAccessibilityStatus: Cursor:<nil> healthStatus:}, Selection: {DynamicData:{} Names:[BACKING_OBJECT_DETAILS VOLUME_TYPE DATASTORE_URL]}","TraceId":"27b1a5cb-320b-46a0-b5af-d0238ac0c79b"}
{"level":"info","time":"2022-06-06T18:04:58.292901635Z","caller":"utils/utils.go:215","msg":"Number of results from QueryAllVolumeUtil: 1","TraceId":"27b1a5cb-320b-46a0-b5af-d0238ac0c79b"}
{"level":"error","time":"2022-06-06T18:04:58.293171282Z","caller":"vanilla/controller.go:951","msg":"volume: 0e21840d-285c-417a-b08d-ff66a23d920a with existing snapshots [size_bytes:1073741824 snapshot_id:\"0e21840d-285c-417a-b08d-ff66a23d920a+7ba8896c-8ea9-49d4-86c3-79809cf65c15\" source_volume_id:\"0e21840d-285c-417a-b08d-ff66a23d920a\" creation_time:<seconds:1654538698 nanos:282969082 > ready_to_use:true ] cannot be deleted, please delete snapshots before deleting the volume","TraceId":"27b1a5cb-320b-46a0-b5af-d0238ac0c79b","stacktrace":"sigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/vanilla.(*controller).DeleteVolume.func1\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/vanilla/controller.go:951\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/vanilla.(*controller).DeleteVolume\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/vanilla/controller.go:973\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/vanilla.TestDeleteVolumeWithSnapshots\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/vanilla/controller_test.go:896\ntesting.tRunner\n\t/usr/local/go/src/testing/testing.go:1439"}
    controller_test.go:903: received error as expected when attempting to delete volume with snapshot, error: rpc error: code = FailedPrecondition desc = volume: 0e21840d-285c-417a-b08d-ff66a23d920a with existing snapshots [size_bytes:1073741824 snapshot_id:"0e21840d-285c-417a-b08d-ff66a23d920a+7ba8896c-8ea9-49d4-86c3-79809cf65c15" source_volume_id:"0e21840d-285c-417a-b08d-ff66a23d920a" creation_time:<seconds:1654538698 nanos:282969082 > ready_to_use:true ] cannot be deleted, please delete snapshots before deleting the volume
--- PASS: TestDeleteVolumeWithSnapshots (0.03s)
=== RUN   TestCreateBlockVolumeSnapshotWithIdempotency
{"level":"info","time":"2022-06-06T18:04:58.294180675Z","caller":"vanilla/controller.go:828","msg":"CreateVolume: called with args {Name:test-pvc-0c608859-8815-46bb-82e5-e5356cd11e73 CapacityRange:required_bytes:1073741824  VolumeCapabilities:[access_mode:<mode:SINGLE_NODE_WRITER > ] Parameters:map[] Secrets:map[] VolumeContentSource:<nil> AccessibilityRequirements:<nil> XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}","TraceId":"084159c0-58b8-4c91-8525-9f9cdd6e9f9b"}
{"level":"info","time":"2022-06-06T18:04:58.311100256Z","caller":"volume/manager.go:410","msg":"CreateVolume: VolumeName: \"test-pvc-0c608859-8815-46bb-82e5-e5356cd11e73\", opId: \"\"","TraceId":"084159c0-58b8-4c91-8525-9f9cdd6e9f9b"}
{"level":"info","time":"2022-06-06T18:04:58.311806117Z","caller":"volume/util.go:322","msg":"Volume created successfully. VolumeName: \"test-pvc-0c608859-8815-46bb-82e5-e5356cd11e73\", volumeID: \"7f1173b5-3ae2-4499-8600-3ba01978053e\"","TraceId":"084159c0-58b8-4c91-8525-9f9cdd6e9f9b"}
{"level":"info","time":"2022-06-06T18:04:58.311865045Z","caller":"vanilla/controller.go:863","msg":"Volume created successfully. Volume Handle: \"7f1173b5-3ae2-4499-8600-3ba01978053e\", PV Name: \"test-pvc-0c608859-8815-46bb-82e5-e5356cd11e73\"","TraceId":"084159c0-58b8-4c91-8525-9f9cdd6e9f9b"}
... skipping 134 lines ...
{"level":"info","time":"2022-06-06T18:04:58.441704159Z","caller":"utils/utils.go:118","msg":"invoking QuerySnapshots in iteration: 1 with offset: 0 and limit: 128, current total results: 0","TraceId":"02c55c26-7034-4079-9661-7312f3e8c8a0"}
{"level":"info","time":"2022-06-06T18:04:58.457415454Z","caller":"utils/utils.go:150","msg":"setting max iteration to 0 for total records count: 0","TraceId":"02c55c26-7034-4079-9661-7312f3e8c8a0"}
{"level":"info","time":"2022-06-06T18:04:58.457544483Z","caller":"utils/utils.go:170","msg":"0 more snapshots to be queried","TraceId":"02c55c26-7034-4079-9661-7312f3e8c8a0"}
{"level":"info","time":"2022-06-06T18:04:58.457623837Z","caller":"utils/utils.go:173","msg":"QuerySnapshots retrieved all records (0) for the SnapshotQuerySpec: {DynamicData:{} VolumeId:{DynamicData:{} Id:a403b937-7c3b-450b-87ae-1c51a56e8201} SnapshotId:<nil>} in 1 iterations","TraceId":"02c55c26-7034-4079-9661-7312f3e8c8a0"}
{"level":"info","time":"2022-06-06T18:04:58.457691417Z","caller":"utils/utils.go:208","msg":"Invoking QueryAllVolumeUtil with Filter: {DynamicData:{} VolumeIds:[{DynamicData:{} Id:a403b937-7c3b-450b-87ae-1c51a56e8201}] Names:[] ContainerClusterIds:[] StoragePolicyId: Datastores:[] Labels:[] ComplianceStatus: DatastoreAccessibilityStatus: Cursor:<nil> healthStatus:}, Selection: {DynamicData:{} Names:[BACKING_OBJECT_DETAILS VOLUME_TYPE DATASTORE_URL]}","TraceId":"02c55c26-7034-4079-9661-7312f3e8c8a0"}
{"level":"info","time":"2022-06-06T18:04:58.467217052Z","caller":"utils/utils.go:215","msg":"Number of results from QueryAllVolumeUtil: 1","TraceId":"02c55c26-7034-4079-9661-7312f3e8c8a0"}
{"level":"error","time":"2022-06-06T18:04:58.467300123Z","caller":"vanilla/controller.go:1701","msg":"the number of snapshots on the source volume a403b937-7c3b-450b-87ae-1c51a56e8201 reaches the configured maximum (3)","TraceId":"02c55c26-7034-4079-9661-7312f3e8c8a0","stacktrace":"sigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/vanilla.(*controller).CreateSnapshot.func1\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/vanilla/controller.go:1701\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/vanilla.(*controller).CreateSnapshot\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/vanilla/controller.go:1735\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/vanilla.TestCreateBlockVolumeSnapshot\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/vanilla/controller_test.go:1210\ntesting.tRunner\n\t/usr/local/go/src/testing/testing.go:1439"}
    controller_test.go:1217: received error as expected when attempting to create snapshot on volume when existing number of snapshots reaches the configured maximum, error: rpc error: code = FailedPrecondition desc = the number of snapshots on the source volume a403b937-7c3b-450b-87ae-1c51a56e8201 reaches the configured maximum (3).
{"level":"info","time":"2022-06-06T18:04:58.467538809Z","caller":"vanilla/controller.go:1751","msg":"DeleteSnapshot: called with args {SnapshotId:a403b937-7c3b-450b-87ae-1c51a56e8201+b0876181-2d0f-4a9a-aa89-77ce2b71e0b8 Secrets:map[] XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}","TraceId":"2bb44623-d81c-4d97-baab-e60f8bfbe46d"}
{"level":"info","time":"2022-06-06T18:04:58.468633084Z","caller":"volume/util.go:415","msg":"Calling CnsClient.DeleteSnapshots: VolumeID [\"a403b937-7c3b-450b-87ae-1c51a56e8201\"] SnapshotID [\"b0876181-2d0f-4a9a-aa89-77ce2b71e0b8\"] cnsSnapshotDeleteSpecList [types.CnsSnapshotDeleteSpec{DynamicData:types.DynamicData{}, VolumeId:types.CnsVolumeId{DynamicData:types.DynamicData{}, Id:\"a403b937-7c3b-450b-87ae-1c51a56e8201\"}, SnapshotId:types.CnsSnapshotId{DynamicData:types.DynamicData{}, Id:\"b0876181-2d0f-4a9a-aa89-77ce2b71e0b8\"}}]","TraceId":"2bb44623-d81c-4d97-baab-e60f8bfbe46d"}
{"level":"info","time":"2022-06-06T18:04:58.47211768Z","caller":"volume/manager.go:2175","msg":"DeleteSnapshot: VolumeID: \"a403b937-7c3b-450b-87ae-1c51a56e8201\", SnapshotID: \"b0876181-2d0f-4a9a-aa89-77ce2b71e0b8\", opId: \"\"","TraceId":"2bb44623-d81c-4d97-baab-e60f8bfbe46d"}
{"level":"info","time":"2022-06-06T18:04:58.47218062Z","caller":"volume/manager.go:2231","msg":"DeleteSnapshot: Snapshot \"b0876181-2d0f-4a9a-aa89-77ce2b71e0b8\" on volume \"a403b937-7c3b-450b-87ae-1c51a56e8201\" is deleted successfully. opId: \"\"","TraceId":"2bb44623-d81c-4d97-baab-e60f8bfbe46d"}
{"level":"info","time":"2022-06-06T18:04:58.472216178Z","caller":"vanilla/controller.go:1779","msg":"DeleteSnapshot: successfully deleted snapshot \"a403b937-7c3b-450b-87ae-1c51a56e8201+b0876181-2d0f-4a9a-aa89-77ce2b71e0b8\"","TraceId":"2bb44623-d81c-4d97-baab-e60f8bfbe46d"}
{"level":"info","time":"2022-06-06T18:04:58.472232764Z","caller":"vanilla/controller.go:1790","msg":"Snapshot \"a403b937-7c3b-450b-87ae-1c51a56e8201+b0876181-2d0f-4a9a-aa89-77ce2b71e0b8\" deleted successfully.","TraceId":"2bb44623-d81c-4d97-baab-e60f8bfbe46d"}
... skipping 54 lines ...
{"level":"info","time":"2022-06-06T18:04:58.555806351Z","caller":"volume/manager.go:410","msg":"CreateVolume: VolumeName: \"test-pvc-bbee75cf-b09d-41d4-8f8d-0b27723b8f1b\", opId: \"\"","TraceId":"a02cbaed-ac90-4e39-a8d4-b9aa5fa9f193"}
{"level":"info","time":"2022-06-06T18:04:58.5566225Z","caller":"volume/util.go:322","msg":"Volume created successfully. VolumeName: \"test-pvc-bbee75cf-b09d-41d4-8f8d-0b27723b8f1b\", volumeID: \"b55ec9ed-2c94-44b2-b769-528b6f77cfc8\"","TraceId":"a02cbaed-ac90-4e39-a8d4-b9aa5fa9f193"}
{"level":"info","time":"2022-06-06T18:04:58.556746485Z","caller":"vanilla/controller.go:863","msg":"Volume created successfully. Volume Handle: \"b55ec9ed-2c94-44b2-b769-528b6f77cfc8\", PV Name: \"test-pvc-bbee75cf-b09d-41d4-8f8d-0b27723b8f1b\"","TraceId":"a02cbaed-ac90-4e39-a8d4-b9aa5fa9f193"}
{"level":"info","time":"2022-06-06T18:04:58.557432121Z","caller":"vanilla/controller.go:828","msg":"CreateVolume: called with args {Name:test-pvc-05b04ae4-dfbb-42d7-a3a7-c40622ae0ce4 CapacityRange:required_bytes:2147483648  VolumeCapabilities:[access_mode:<mode:SINGLE_NODE_WRITER > ] Parameters:map[] Secrets:map[] VolumeContentSource:snapshot:<snapshot_id:\"552a93cd-c49e-4f0e-84d7-762298d480c5+1cc67830-241d-4c1f-af87-bd85a7e8305a\" >  AccessibilityRequirements:<nil> XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}","TraceId":"c75c72dd-d962-48e9-9bfe-e31a6b66eb6f"}
{"level":"info","time":"2022-06-06T18:04:58.55749845Z","caller":"utils/utils.go:208","msg":"Invoking QueryAllVolumeUtil with Filter: {DynamicData:{} VolumeIds:[{DynamicData:{} Id:552a93cd-c49e-4f0e-84d7-762298d480c5}] Names:[] ContainerClusterIds:[] StoragePolicyId: Datastores:[] Labels:[] ComplianceStatus: DatastoreAccessibilityStatus: Cursor:<nil> healthStatus:}, Selection: {DynamicData:{} Names:[BACKING_OBJECT_DETAILS VOLUME_TYPE DATASTORE_URL]}","TraceId":"c75c72dd-d962-48e9-9bfe-e31a6b66eb6f"}
{"level":"info","time":"2022-06-06T18:04:58.558651496Z","caller":"utils/utils.go:215","msg":"Number of results from QueryAllVolumeUtil: 1","TraceId":"c75c72dd-d962-48e9-9bfe-e31a6b66eb6f"}
{"level":"error","time":"2022-06-06T18:04:58.558695106Z","caller":"vanilla/controller.go:435","msg":"size mismatches, requested volume size 2147483648 and source snapshot size 1073741824","TraceId":"c75c72dd-d962-48e9-9bfe-e31a6b66eb6f","stacktrace":"sigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/vanilla.(*controller).createBlockVolume\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/vanilla/controller.go:435\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/vanilla.(*controller).CreateVolume.func1\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/vanilla/controller.go:855\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/vanilla.(*controller).CreateVolume\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/vanilla/controller.go:857\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/vanilla.TestCreateVolumeFromSnapshot\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/vanilla/controller_test.go:1418\ntesting.tRunner\n\t/usr/local/go/src/testing/testing.go:1439"}
    controller_test.go:1425: received error as expected when attempting to create volume from snapshot, error: rpc error: code = InvalidArgument desc = size mismatches, requested volume size 2147483648 and source snapshot size 1073741824
{"level":"info","time":"2022-06-06T18:04:58.561602316Z","caller":"vanilla/controller.go:881","msg":"DeleteVolume: called with args: {VolumeId:b55ec9ed-2c94-44b2-b769-528b6f77cfc8 Secrets:map[] XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}","TraceId":"b4c0342a-5fbb-4465-81ac-291dd81f6d39"}
{"level":"info","time":"2022-06-06T18:04:58.563224596Z","caller":"common/vsphereutil.go:1095","msg":"volume: b55ec9ed-2c94-44b2-b769-528b6f77cfc8 is of type: BLOCK","TraceId":"b4c0342a-5fbb-4465-81ac-291dd81f6d39"}
{"level":"info","time":"2022-06-06T18:04:58.563289551Z","caller":"utils/utils.go:93","msg":"Invoking QuerySnapshots with spec: {DynamicData:{} VolumeId:{DynamicData:{} Id:b55ec9ed-2c94-44b2-b769-528b6f77cfc8} SnapshotId:<nil>}","TraceId":"b4c0342a-5fbb-4465-81ac-291dd81f6d39"}
{"level":"info","time":"2022-06-06T18:04:58.563306305Z","caller":"utils/utils.go:118","msg":"invoking QuerySnapshots in iteration: 1 with offset: 0 and limit: 128, current total results: 0","TraceId":"b4c0342a-5fbb-4465-81ac-291dd81f6d39"}
{"level":"info","time":"2022-06-06T18:04:58.590304408Z","caller":"utils/utils.go:131","msg":"QuerySnapshots retrieved no results for the spec: {DynamicData:{} VolumeId:{DynamicData:{} Id:b55ec9ed-2c94-44b2-b769-528b6f77cfc8} SnapshotId:<nil>}","TraceId":"b4c0342a-5fbb-4465-81ac-291dd81f6d39"}
{"level":"info","time":"2022-06-06T18:04:58.590374209Z","caller":"utils/utils.go:150","msg":"setting max iteration to 0 for total records count: 0","TraceId":"b4c0342a-5fbb-4465-81ac-291dd81f6d39"}
... skipping 473 lines ...
{"level":"info","time":"2022-06-06T18:04:59.030662059Z","caller":"utils/utils.go:118","msg":"invoking QuerySnapshots in iteration: 1 with offset: 0 and limit: 128, current total results: 0","TraceId":"645569f8-c10f-485f-84a9-883fc3f60cda"}
{"level":"info","time":"2022-06-06T18:04:59.035123642Z","caller":"utils/utils.go:150","msg":"setting max iteration to 0 for total records count: 0","TraceId":"645569f8-c10f-485f-84a9-883fc3f60cda"}
{"level":"info","time":"2022-06-06T18:04:59.035176167Z","caller":"utils/utils.go:170","msg":"0 more snapshots to be queried","TraceId":"645569f8-c10f-485f-84a9-883fc3f60cda"}
{"level":"info","time":"2022-06-06T18:04:59.035200168Z","caller":"utils/utils.go:173","msg":"QuerySnapshots retrieved all records (0) for the SnapshotQuerySpec: {DynamicData:{} VolumeId:{DynamicData:{} Id:d5c30753-9869-4875-9688-777c2d384e68} SnapshotId:<nil>} in 1 iterations","TraceId":"645569f8-c10f-485f-84a9-883fc3f60cda"}
{"level":"info","time":"2022-06-06T18:04:59.035233784Z","caller":"utils/utils.go:208","msg":"Invoking QueryAllVolumeUtil with Filter: {DynamicData:{} VolumeIds:[{DynamicData:{} Id:d5c30753-9869-4875-9688-777c2d384e68}] Names:[] ContainerClusterIds:[] StoragePolicyId: Datastores:[] Labels:[] ComplianceStatus: DatastoreAccessibilityStatus: Cursor:<nil> healthStatus:}, Selection: {DynamicData:{} Names:[BACKING_OBJECT_DETAILS VOLUME_TYPE DATASTORE_URL]}","TraceId":"645569f8-c10f-485f-84a9-883fc3f60cda"}
{"level":"info","time":"2022-06-06T18:04:59.036599254Z","caller":"utils/utils.go:215","msg":"Number of results from QueryAllVolumeUtil: 1","TraceId":"645569f8-c10f-485f-84a9-883fc3f60cda"}
{"level":"error","time":"2022-06-06T18:04:59.036691543Z","caller":"vanilla/controller.go:1297","msg":"volume: d5c30753-9869-4875-9688-777c2d384e68 with existing snapshots [size_bytes:1073741824 snapshot_id:\"d5c30753-9869-4875-9688-777c2d384e68+08b69790-9d32-4833-b46c-a1a476dc1951\" source_volume_id:\"d5c30753-9869-4875-9688-777c2d384e68\" creation_time:<seconds:1654538699 nanos:26446776 > ready_to_use:true ] cannot be expanded. Please delete snapshots before expanding the volume","TraceId":"645569f8-c10f-485f-84a9-883fc3f60cda","stacktrace":"sigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/vanilla.(*controller).ControllerExpandVolume.func1\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/vanilla/controller.go:1297\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/vanilla.(*controller).ControllerExpandVolume\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/vanilla/controller.go:1329\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/vanilla.TestExpandVolumeWithSnapshots\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/vanilla/controller_test.go:2002\ntesting.tRunner\n\t/usr/local/go/src/testing/testing.go:1439"}
    controller_test.go:2009: received error as expected when attempting to expand volume with snapshot, error: rpc error: code = FailedPrecondition desc = volume: d5c30753-9869-4875-9688-777c2d384e68 with existing snapshots [size_bytes:1073741824 snapshot_id:"d5c30753-9869-4875-9688-777c2d384e68+08b69790-9d32-4833-b46c-a1a476dc1951" source_volume_id:"d5c30753-9869-4875-9688-777c2d384e68" creation_time:<seconds:1654538699 nanos:26446776 > ready_to_use:true ] cannot be expanded. Please delete snapshots before expanding the volume
{"level":"info","time":"2022-06-06T18:04:59.036977976Z","caller":"vanilla/controller.go:1751","msg":"DeleteSnapshot: called with args {SnapshotId:d5c30753-9869-4875-9688-777c2d384e68+08b69790-9d32-4833-b46c-a1a476dc1951 Secrets:map[] XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}","TraceId":"157daa35-c903-4bea-b024-f9ea014ffb6e"}
{"level":"info","time":"2022-06-06T18:04:59.037817482Z","caller":"volume/util.go:415","msg":"Calling CnsClient.DeleteSnapshots: VolumeID [\"d5c30753-9869-4875-9688-777c2d384e68\"] SnapshotID [\"08b69790-9d32-4833-b46c-a1a476dc1951\"] cnsSnapshotDeleteSpecList [types.CnsSnapshotDeleteSpec{DynamicData:types.DynamicData{}, VolumeId:types.CnsVolumeId{DynamicData:types.DynamicData{}, Id:\"d5c30753-9869-4875-9688-777c2d384e68\"}, SnapshotId:types.CnsSnapshotId{DynamicData:types.DynamicData{}, Id:\"08b69790-9d32-4833-b46c-a1a476dc1951\"}}]","TraceId":"157daa35-c903-4bea-b024-f9ea014ffb6e"}
{"level":"info","time":"2022-06-06T18:04:59.040445215Z","caller":"volume/manager.go:2175","msg":"DeleteSnapshot: VolumeID: \"d5c30753-9869-4875-9688-777c2d384e68\", SnapshotID: \"08b69790-9d32-4833-b46c-a1a476dc1951\", opId: \"\"","TraceId":"157daa35-c903-4bea-b024-f9ea014ffb6e"}
{"level":"info","time":"2022-06-06T18:04:59.040495947Z","caller":"volume/manager.go:2231","msg":"DeleteSnapshot: Snapshot \"08b69790-9d32-4833-b46c-a1a476dc1951\" on volume \"d5c30753-9869-4875-9688-777c2d384e68\" is deleted successfully. opId: \"\"","TraceId":"157daa35-c903-4bea-b024-f9ea014ffb6e"}
{"level":"info","time":"2022-06-06T18:04:59.040526995Z","caller":"vanilla/controller.go:1779","msg":"DeleteSnapshot: successfully deleted snapshot \"d5c30753-9869-4875-9688-777c2d384e68+08b69790-9d32-4833-b46c-a1a476dc1951\"","TraceId":"157daa35-c903-4bea-b024-f9ea014ffb6e"}
{"level":"info","time":"2022-06-06T18:04:59.040539634Z","caller":"vanilla/controller.go:1790","msg":"Snapshot \"d5c30753-9869-4875-9688-777c2d384e68+08b69790-9d32-4833-b46c-a1a476dc1951\" deleted successfully.","TraceId":"157daa35-c903-4bea-b024-f9ea014ffb6e"}
... skipping 15 lines ...
=== RUN   TestDeleteBlockVolumeSnapshotWithManagedObjectNotFound
{"level":"info","time":"2022-06-06T18:04:59.054153806Z","caller":"vanilla/controller.go:828","msg":"CreateVolume: called with args {Name:test-pvc-a0ed318c-1e1f-4a00-a8fb-a593748babd0 CapacityRange:required_bytes:1073741824  VolumeCapabilities:[access_mode:<mode:SINGLE_NODE_WRITER > ] Parameters:map[] Secrets:map[] VolumeContentSource:<nil> AccessibilityRequirements:<nil> XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}","TraceId":"80691aa6-b0d6-42a0-bbf0-a39f231e8063"}
{"level":"info","time":"2022-06-06T18:04:59.063918705Z","caller":"volume/manager.go:410","msg":"CreateVolume: VolumeName: \"test-pvc-a0ed318c-1e1f-4a00-a8fb-a593748babd0\", opId: \"\"","TraceId":"80691aa6-b0d6-42a0-bbf0-a39f231e8063"}
{"level":"info","time":"2022-06-06T18:04:59.064582995Z","caller":"volume/util.go:322","msg":"Volume created successfully. VolumeName: \"test-pvc-a0ed318c-1e1f-4a00-a8fb-a593748babd0\", volumeID: \"ec2fb5cd-c255-444f-aa93-c2384aafa010\"","TraceId":"80691aa6-b0d6-42a0-bbf0-a39f231e8063"}
{"level":"info","time":"2022-06-06T18:04:59.0646315Z","caller":"vanilla/controller.go:863","msg":"Volume created successfully. Volume Handle: \"ec2fb5cd-c255-444f-aa93-c2384aafa010\", PV Name: \"test-pvc-a0ed318c-1e1f-4a00-a8fb-a593748babd0\"","TraceId":"80691aa6-b0d6-42a0-bbf0-a39f231e8063"}
{"level":"info","time":"2022-06-06T18:04:59.072581076Z","caller":"vanilla/controller.go:1751","msg":"DeleteSnapshot: called with args {SnapshotId:ec2fb5cd-c255-444f-aa93-c2384aafa010+e4523901-037b-4684-becc-5d72ef706b3b Secrets:map[] XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}","TraceId":"371e5c70-96f0-441d-8ec3-79b104afc1bb"}
{"level":"info","time":"2022-06-06T18:04:59.076814212Z","caller":"volume/manager.go:2149","msg":"Snapshot \"e4523901-037b-4684-becc-5d72ef706b3b\" on volume \"ec2fb5cd-c255-444f-aa93-c2384aafa010\" might have already been deleted with the error ServerFaultCode: ManagedObjectNotFound. Calling CNS QuerySnapshots API to confirm it","TraceId":"371e5c70-96f0-441d-8ec3-79b104afc1bb"}
{"level":"info","time":"2022-06-06T18:04:59.080934077Z","caller":"volume/util.go:495","msg":"fault in the result of query CNS for snapshot e4523901-037b-4684-becc-5d72ef706b3b on volume ec2fb5cd-c255-444f-aa93-c2384aafa010: (types.CnsSnapshotNotFoundFault) {\n CnsFault: (types.CnsFault) {\n  BaseMethodFault: (types.BaseMethodFault) <nil>,\n  Reason: (string) \"\"\n },\n VolumeId: (types.CnsVolumeId) {\n  DynamicData: (types.DynamicData) {\n  },\n  Id: (string) (len=36) \"ec2fb5cd-c255-444f-aa93-c2384aafa010\"\n },\n SnapshotId: (types.CnsSnapshotId) {\n  DynamicData: (types.DynamicData) {\n  },\n  Id: (string) (len=36) \"e4523901-037b-4684-becc-5d72ef706b3b\"\n }\n}\n","TraceId":"371e5c70-96f0-441d-8ec3-79b104afc1bb"}
{"level":"info","time":"2022-06-06T18:04:59.081012985Z","caller":"volume/manager.go:2160","msg":"DeleteSnapshot: Snapshot \"e4523901-037b-4684-becc-5d72ef706b3b\" on volume \"ec2fb5cd-c255-444f-aa93-c2384aafa010\" is confirmed to be deleted successfully","TraceId":"371e5c70-96f0-441d-8ec3-79b104afc1bb"}
{"level":"info","time":"2022-06-06T18:04:59.081044898Z","caller":"vanilla/controller.go:1779","msg":"DeleteSnapshot: successfully deleted snapshot \"ec2fb5cd-c255-444f-aa93-c2384aafa010+e4523901-037b-4684-becc-5d72ef706b3b\"","TraceId":"371e5c70-96f0-441d-8ec3-79b104afc1bb"}
{"level":"info","time":"2022-06-06T18:04:59.081957106Z","caller":"vanilla/controller.go:1790","msg":"Snapshot \"ec2fb5cd-c255-444f-aa93-c2384aafa010+e4523901-037b-4684-becc-5d72ef706b3b\" deleted successfully.","TraceId":"371e5c70-96f0-441d-8ec3-79b104afc1bb"}
{"level":"info","time":"2022-06-06T18:04:59.082139587Z","caller":"vanilla/controller.go:881","msg":"DeleteVolume: called with args: {VolumeId:ec2fb5cd-c255-444f-aa93-c2384aafa010 Secrets:map[] XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}","TraceId":"92534cfc-de80-4e0e-aa50-0b702d78a8ad"}
{"level":"info","time":"2022-06-06T18:04:59.08370015Z","caller":"common/vsphereutil.go:1095","msg":"volume: ec2fb5cd-c255-444f-aa93-c2384aafa010 is of type: BLOCK","TraceId":"92534cfc-de80-4e0e-aa50-0b702d78a8ad"}
... skipping 69 lines ...
{"level":"info","time":"2022-06-06T18:04:59.165808545Z","caller":"volume/manager.go:1039","msg":"DeleteVolume: Volume deleted successfully. volumeID: \"cb949280-b7c8-4180-94db-50f3f3c73d57\", opId: \"\"","TraceId":"018e44ed-41cc-4b62-9edf-5fb5e394abf1"}
{"level":"info","time":"2022-06-06T18:04:59.165843009Z","caller":"vanilla/controller.go:979","msg":"Volume \"cb949280-b7c8-4180-94db-50f3f3c73d57\" deleted successfully.","TraceId":"018e44ed-41cc-4b62-9edf-5fb5e394abf1"}
--- PASS: TestCreateSnapshotWithManagedObjectNotFound (0.07s)
PASS
ok  	sigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/vanilla	1.492s
=== RUN   TestWCPCreateVolumeWithStoragePolicy
{"level":"error","time":"2022-06-06T18:04:59.270512882Z","caller":"config/config.go:311","msg":"no Virtual Center hosts defined","stacktrace":"sigs.k8s.io/vsphere-csi-driver/v2/pkg/common/config.validateConfig\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/common/config/config.go:311\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/common/config.FromEnv\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/common/config/config.go:295\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/wcp.configFromEnvOrSim\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/wcp/controller_test.go:131\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/wcp.getControllerTest.func1\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/wcp/controller_test.go:141\nsync.(*Once).doSlow\n\t/usr/local/go/src/sync/once.go:68\nsync.(*Once).Do\n\t/usr/local/go/src/sync/once.go:59\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/wcp.getControllerTest\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/wcp/controller_test.go:138\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/wcp.TestWCPCreateVolumeWithStoragePolicy\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/wcp/controller_test.go:271\ntesting.tRunner\n\t/usr/local/go/src/testing/testing.go:1439"}
{"level":"info","time":"2022-06-06T18:04:59.636952134Z","caller":"vsphere/utils.go:189","msg":"Defaulting timeout for vCenter Client to 5 minutes"}
{"level":"info","time":"2022-06-06T18:04:59.637044409Z","caller":"vsphere/virtualcentermanager.go:74","msg":"Initializing defaultVirtualCenterManager..."}
{"level":"info","time":"2022-06-06T18:04:59.637062885Z","caller":"vsphere/virtualcentermanager.go:76","msg":"Successfully initialized defaultVirtualCenterManager"}
{"level":"info","time":"2022-06-06T18:04:59.637103359Z","caller":"vsphere/virtualcentermanager.go:122","msg":"Successfully registered VC \"127.0.0.1\""}
{"level":"info","time":"2022-06-06T18:04:59.645929234Z","caller":"vsphere/virtualcenter.go:183","msg":"New session ID for 'user' = a207a30d-80d0-4626-9701-c98893527d37"}
{"level":"info","time":"2022-06-06T18:04:59.646836634Z","caller":"volume/manager.go:175","msg":"Initializing new defaultManager..."}
... skipping 5 lines ...
{"level":"info","time":"2022-06-06T18:04:59.68011872Z","caller":"volume/manager.go:1014","msg":"DeleteVolume: volumeID: \"ddd751a0-1777-4518-936b-782e9f57886c\", opId: \"\"","TraceId":"d8dbad54-f57a-4db3-b9d2-3db9565a7168"}
{"level":"info","time":"2022-06-06T18:04:59.680166629Z","caller":"volume/manager.go:1039","msg":"DeleteVolume: Volume deleted successfully. volumeID: \"ddd751a0-1777-4518-936b-782e9f57886c\", opId: \"\"","TraceId":"d8dbad54-f57a-4db3-b9d2-3db9565a7168"}
{"level":"info","time":"2022-06-06T18:04:59.680211346Z","caller":"wcp/controller.go:839","msg":"Volume \"ddd751a0-1777-4518-936b-782e9f57886c\" deleted successfully.","TraceId":"d8dbad54-f57a-4db3-b9d2-3db9565a7168"}
--- PASS: TestWCPCreateVolumeWithStoragePolicy (0.41s)
=== RUN   TestWCPCreateVolumeWithZonalLabelPresentButNoStorageTopoType
{"level":"info","time":"2022-06-06T18:04:59.69102004Z","caller":"wcp/controller.go:746","msg":"CreateVolume: called with args {Name:test-pvc-f8a638fc-5faf-4d20-8a82-87affbbdfe22 CapacityRange:required_bytes:1073741824  VolumeCapabilities:[access_mode:<mode:SINGLE_NODE_WRITER > ] Parameters:map[storagepolicyid:aa6d5a82-1c88-45da-85d3-3d74b91a5bad] Secrets:map[] VolumeContentSource:<nil> AccessibilityRequirements:preferred:<segments:<key:\"topology.kubernetes.io/zone\" value:\"zone1\" > >  XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}","TraceId":"bcc444c1-6fb7-436a-bf72-8ff1450f5977"}
{"level":"error","time":"2022-06-06T18:04:59.691911687Z","caller":"wcp/controller.go:432","msg":"StorageTopologyType is unset while topology label is present","TraceId":"bcc444c1-6fb7-436a-bf72-8ff1450f5977","stacktrace":"sigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/wcp.(*controller).createBlockVolume\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/wcp/controller.go:432\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/wcp.(*controller).CreateVolume.func1\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/wcp/controller.go:782\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/wcp.(*controller).CreateVolume\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/wcp/controller.go:784\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/wcp.TestWCPCreateVolumeWithZonalLabelPresentButNoStorageTopoType\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/wcp/controller_test.go:436\ntesting.tRunner\n\t/usr/local/go/src/testing/testing.go:1439"}
    controller_test.go:438: expected error is thrown: rpc error: code = InvalidArgument desc = StorageTopologyType is unset while topology label is present
--- PASS: TestWCPCreateVolumeWithZonalLabelPresentButNoStorageTopoType (0.01s)
PASS
ok  	sigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/wcp	0.468s
=== RUN   TestGuestClusterControllerFlow
{"level":"error","time":"2022-06-06T18:04:57.761843484Z","caller":"config/config.go:582","msg":"no Supervisor Cluster endpoint defined in Guest Cluster config","stacktrace":"sigs.k8s.io/vsphere-csi-driver/v2/pkg/common/config.validateGCConfig\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/common/config/config.go:582\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/common/config.FromEnvToGC\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/common/config/config.go:522\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/wcpguest.configFromEnvOrSim\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/wcpguest/controller_test.go:72\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/wcpguest.getControllerTest.func1\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/wcpguest/controller_test.go:88\nsync.(*Once).doSlow\n\t/usr/local/go/src/sync/once.go:68\nsync.(*Once).Do\n\t/usr/local/go/src/sync/once.go:59\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/wcpguest.getControllerTest\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/wcpguest/controller_test.go:85\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/wcpguest.TestGuestClusterControllerFlow\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/csi/service/wcpguest/controller_test.go:121\ntesting.tRunner\n\t/usr/local/go/src/testing/testing.go:1439"}
{"level":"info","time":"2022-06-06T18:04:57.765001518Z","caller":"wcpguest/controller.go:233","msg":"CreateVolume: called with args {Name:pvc-12345 CapacityRange:required_bytes:1073741824  VolumeCapabilities:[access_mode:<mode:SINGLE_NODE_WRITER > ] Parameters:map[svstorageclass:test-storageclass] Secrets:map[] VolumeContentSource:<nil> AccessibilityRequirements:<nil> XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}","TraceId":"38340c55-0788-4eb6-9400-f51c64778b8e"}
{"level":"info","time":"2022-06-06T18:04:57.765270375Z","caller":"wcpguest/controller_helper.go:257","msg":"Waiting up to 240 seconds for PersistentVolumeClaim -12345 in namespace test-namespace to have phase Bound","TraceId":"38340c55-0788-4eb6-9400-f51c64778b8e"}
{"level":"info","time":"2022-06-06T18:05:02.765459044Z","caller":"wcpguest/controller_helper.go:273","msg":"PersistentVolumeClaim -12345 in namespace test-namespace is in state Bound","TraceId":"38340c55-0788-4eb6-9400-f51c64778b8e"}
{"level":"info","time":"2022-06-06T18:05:02.765684721Z","caller":"wcpguest/controller.go:379","msg":"Volume created successfully. Volume Handle: \"-12345\", PV Name: \"pvc-12345\"","TraceId":"38340c55-0788-4eb6-9400-f51c64778b8e"}
{"level":"info","time":"2022-06-06T18:05:02.765931824Z","caller":"wcpguest/controller.go:398","msg":"DeleteVolume: called with args: {VolumeId:-12345 Secrets:map[] XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}","TraceId":"5fad3a27-7e79-448c-bd94-54da16d3cfd1"}
{"level":"info","time":"2022-06-06T18:05:02.765995373Z","caller":"wcpguest/controller.go:443","msg":"DeleteVolume: Volume deleted successfully. VolumeID: \"-12345\"","TraceId":"5fad3a27-7e79-448c-bd94-54da16d3cfd1"}
... skipping 20 lines ...
=== RUN   TestGenerateVolumeAccessibleTopologyFromPVCAnnotation
    controller_test.go:347: Calling generateVolumeAccessibleTopologyFromPVCAnnotation with csi.vsphere.volume-accessible-topology annotation value "[{\"topology.kubernetes.io/zone\":\"zone1\"},{\"topology.kubernetes.io/zone\":\"zone2\"}]"
    controller_test.go:365: accessibleTopologies [map[topology.kubernetes.io/zone:zone1] map[topology.kubernetes.io/zone:zone2]] match with expectedAccessibleTopologies: [map[topology.kubernetes.io/zone:zone1] map[topology.kubernetes.io/zone:zone2]]
--- PASS: TestGenerateVolumeAccessibleTopologyFromPVCAnnotation (0.00s)
=== RUN   TestGenerateVolumeAccessibleTopologyFromInvalidPVCAnnotation
    controller_test.go:382: Calling generateVolumeAccessibleTopologyFromPVCAnnotation with csi.vsphere.volume-accessible-topology annotation value "[{\"topology.kubernetes.io/zone\":\"zone1\",{\"topology.kubernetes.io/zone\":\"zone2\"}]"
    controller_test.go:391: expected error: failed to parse annotation: "csi.vsphere.volume-accessible-topology" value [{"topology.kubernetes.io/zone":"zone1",{"topology.kubernetes.io/zone":"zone2"}] from the claim: "name", namespace: "ns". err: invalid character '{' looking for beginning of object key string
--- PASS: TestGenerateVolumeAccessibleTopologyFromInvalidPVCAnnotation (0.00s)
=== RUN   TestGenerateGuestClusterRequestedTopologyJSON
    controller_test.go:404: Calling generateGuestClusterRequestedTopologyJSON with topologies: [segments:<key:"topology.kubernetes.io/zone" value:"zone1" >  segments:<key:"topology.kubernetes.io/zone" value:"zone2" > ]
    controller_test.go:416: volumeAccessibleTopologyJSON [{"topology.kubernetes.io/zone":"zone1"},{"topology.kubernetes.io/zone":"zone2"}] match with expectedVolumeAccessibleTopologyJSON: [{"topology.kubernetes.io/zone":"zone1"},{"topology.kubernetes.io/zone":"zone2"}]
--- PASS: TestGenerateGuestClusterRequestedTopologyJSON (0.00s)
PASS
ok  	sigs.k8s.io/vsphere-csi-driver/v2/pkg/csi/service/wcpguest	18.060s
=== RUN   TestSyncerWorkflows
    syncer_test.go:161: TestSyncerWorkflows: start
{"level":"error","time":"2022-06-06T18:05:02.381815105Z","caller":"config/config.go:311","msg":"no Virtual Center hosts defined","stacktrace":"sigs.k8s.io/vsphere-csi-driver/v2/pkg/common/config.validateConfig\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/common/config/config.go:311\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/common/config.FromEnv\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/common/config/config.go:295\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/syncer.configFromEnvOrSim\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/syncer/syncer_test.go:150\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/syncer.TestSyncerWorkflows\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/syncer/syncer_test.go:163\ntesting.tRunner\n\t/usr/local/go/src/testing/testing.go:1439"}
{"level":"info","time":"2022-06-06T18:05:02.769753586Z","caller":"vsphere/utils.go:189","msg":"Defaulting timeout for vCenter Client to 5 minutes"}
{"level":"info","time":"2022-06-06T18:05:02.76985467Z","caller":"vsphere/virtualcentermanager.go:74","msg":"Initializing defaultVirtualCenterManager..."}
{"level":"info","time":"2022-06-06T18:05:02.769875599Z","caller":"vsphere/virtualcentermanager.go:76","msg":"Successfully initialized defaultVirtualCenterManager"}
{"level":"info","time":"2022-06-06T18:05:02.769917545Z","caller":"vsphere/virtualcentermanager.go:122","msg":"Successfully registered VC \"127.0.0.1\""}
{"level":"info","time":"2022-06-06T18:05:02.781529561Z","caller":"vsphere/virtualcenter.go:183","msg":"New session ID for 'user' = fccacd5f-67d7-4c2c-b4dd-ff0be628aecc"}
{"level":"info","time":"2022-06-06T18:05:02.782541524Z","caller":"volume/manager.go:175","msg":"Initializing new defaultManager..."}
... skipping 158 lines ...
    --- PASS: TestValidatePVCAnnotationForVolumeHealth/TestUpdatePVCAnnVolumeHealthToInaccessibleByCSIServiceAccount (0.00s)
    --- PASS: TestValidatePVCAnnotationForVolumeHealth/TestUpdatePVCAnnVolumeHealthToAccessibleByCSIServiceAccount (0.00s)
    --- PASS: TestValidatePVCAnnotationForVolumeHealth/TestUpdatePVCRemoveAnnVolumeHealthByDevopsUser (0.00s)
    --- PASS: TestValidatePVCAnnotationForVolumeHealth/TestUpdatePVCRemoveAnnVolumeHealthByCSIServiceAccount (0.00s)
=== RUN   TestValidateStorageClassForAllowVolumeExpansion
{"level":"info","time":"2022-06-06T18:04:57.666087661Z","caller":"admissionhandler/validatestorageclass.go:77","msg":"Validating StorageClass: \"sc\""}
{"level":"error","time":"2022-06-06T18:04:57.666142933Z","caller":"admissionhandler/validatestorageclass.go:101","msg":"validation of StorageClass: \"sc\" Failed","stacktrace":"sigs.k8s.io/vsphere-csi-driver/v2/pkg/syncer/admissionhandler.validateStorageClass\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/syncer/admissionhandler/validatestorageclass.go:101\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/syncer/admissionhandler.TestValidateStorageClassForAllowVolumeExpansion\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/syncer/admissionhandler/validatestorageclass_test.go:53\ntesting.tRunner\n\t/usr/local/go/src/testing/testing.go:1439"}
    validatestorageclass_test.go:59: TestValidateStorageClassForAllowVolumeExpansion Passed
--- PASS: TestValidateStorageClassForAllowVolumeExpansion (0.00s)
=== RUN   TestValidateStorageClassForMigrationParameter
{"level":"info","time":"2022-06-06T18:04:57.66637241Z","caller":"admissionhandler/validatestorageclass.go:77","msg":"Validating StorageClass: \"sc\""}
{"level":"error","time":"2022-06-06T18:04:57.666407802Z","caller":"admissionhandler/validatestorageclass.go:101","msg":"validation of StorageClass: \"sc\" Failed","stacktrace":"sigs.k8s.io/vsphere-csi-driver/v2/pkg/syncer/admissionhandler.validateStorageClass\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/syncer/admissionhandler/validatestorageclass.go:101\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/syncer/admissionhandler.TestValidateStorageClassForMigrationParameter\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/syncer/admissionhandler/validatestorageclass_test.go:77\ntesting.tRunner\n\t/usr/local/go/src/testing/testing.go:1439"}
{"level":"info","time":"2022-06-06T18:04:57.66655101Z","caller":"admissionhandler/validatestorageclass.go:77","msg":"Validating StorageClass: \"sc\""}
{"level":"error","time":"2022-06-06T18:04:57.666581589Z","caller":"admissionhandler/validatestorageclass.go:101","msg":"validation of StorageClass: \"sc\" Failed","stacktrace":"sigs.k8s.io/vsphere-csi-driver/v2/pkg/syncer/admissionhandler.validateStorageClass\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/syncer/admissionhandler/validatestorageclass.go:101\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/syncer/admissionhandler.TestValidateStorageClassForMigrationParameter\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/syncer/admissionhandler/validatestorageclass_test.go:91\ntesting.tRunner\n\t/usr/local/go/src/testing/testing.go:1439"}
    validatestorageclass_test.go:98: TestValidateStorageClassForMigrationParameter Passed
--- PASS: TestValidateStorageClassForMigrationParameter (0.00s)
=== RUN   TestValidateStorageClassForValidStorageClass
{"level":"info","time":"2022-06-06T18:04:57.667155261Z","caller":"admissionhandler/validatestorageclass.go:77","msg":"Validating StorageClass: \"sc\""}
{"level":"info","time":"2022-06-06T18:04:57.667190644Z","caller":"admissionhandler/validatestorageclass.go:99","msg":"Validation of StorageClass: \"sc\" Passed"}
    validatestorageclass_test.go:120: TestValidateStorageClassForValidStorageClass Passed
... skipping 6 lines ...
{"level":"info","time":"2022-06-06T18:05:01.343521393Z","caller":"csinodetopology/csinodetopology_controller.go:393","msg":"Successfully updated topology labels for worker \"test-csinodetopology-name\" in GUEST_CLUSTER"}
=== RUN   TestCSINodeTopologyControllerForTKGSHA/TestWithVmStatusZoneEmpty
{"level":"info","time":"2022-06-06T18:05:01.344161084Z","caller":"csinodetopology/csinodetopology_controller.go:342","msg":"Start reconciling the CSINodeTopology request test-csinodetopology-name in GUEST_CLUSTER"}
{"level":"info","time":"2022-06-06T18:05:01.344299554Z","caller":"csinodetopology/csinodetopology_controller.go:393","msg":"Successfully updated topology labels for worker \"test-csinodetopology-name\" in GUEST_CLUSTER"}
=== RUN   TestCSINodeTopologyControllerForTKGSHA/TestWithGetVmFailure
{"level":"info","time":"2022-06-06T18:05:01.344491275Z","caller":"csinodetopology/csinodetopology_controller.go:342","msg":"Start reconciling the CSINodeTopology request test-csinodetopology-name in GUEST_CLUSTER"}
{"level":"error","time":"2022-06-06T18:05:01.344585976Z","caller":"csinodetopology/csinodetopology_controller.go:410","msg":"failed to get VirtualMachines for the node: \"test-csinodetopology-name\". Error: virtualmachines.vmoperator.vmware.com \"test-csinodetopology-name\" not found","stacktrace":"sigs.k8s.io/vsphere-csi-driver/v2/pkg/syncer/cnsoperator/controller/csinodetopology.getNodeTopologyInfoForGuest\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/syncer/cnsoperator/controller/csinodetopology/csinodetopology_controller.go:410\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/syncer/cnsoperator/controller/csinodetopology.(*ReconcileCSINodeTopology).reconcileForGuest\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/syncer/cnsoperator/controller/csinodetopology/csinodetopology_controller.go:370\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/syncer/cnsoperator/controller/csinodetopology.(*ReconcileCSINodeTopology).Reconcile\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/syncer/cnsoperator/controller/csinodetopology/csinodetopology_controller.go:225\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/syncer/cnsoperator/controller/csinodetopology.TestCSINodeTopologyControllerForTKGSHA.func1\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/syncer/cnsoperator/controller/csinodetopology/csinodetopology_controller_test.go:175\ntesting.tRunner\n\t/usr/local/go/src/testing/testing.go:1439"}
{"level":"error","time":"2022-06-06T18:05:01.344667838Z","caller":"csinodetopology/csinodetopology_controller.go:374","msg":"failed to fetch topology information for the worker node \"test-csinodetopology-name\". Error: failed to get VirtualMachines for the node: \"test-csinodetopology-name\". Error: virtualmachines.vmoperator.vmware.com \"test-csinodetopology-name\" not found","stacktrace":"sigs.k8s.io/vsphere-csi-driver/v2/pkg/syncer/cnsoperator/controller/csinodetopology.(*ReconcileCSINodeTopology).reconcileForGuest\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/syncer/cnsoperator/controller/csinodetopology/csinodetopology_controller.go:374\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/syncer/cnsoperator/controller/csinodetopology.(*ReconcileCSINodeTopology).Reconcile\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/syncer/cnsoperator/controller/csinodetopology/csinodetopology_controller.go:225\nsigs.k8s.io/vsphere-csi-driver/v2/pkg/syncer/cnsoperator/controller/csinodetopology.TestCSINodeTopologyControllerForTKGSHA.func1\n\t/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver/pkg/syncer/cnsoperator/controller/csinodetopology/csinodetopology_controller_test.go:175\ntesting.tRunner\n\t/usr/local/go/src/testing/testing.go:1439"}
--- PASS: TestCSINodeTopologyControllerForTKGSHA (0.01s)
    --- PASS: TestCSINodeTopologyControllerForTKGSHA/TestWithVmStatusZonePopulated (0.00s)
    --- PASS: TestCSINodeTopologyControllerForTKGSHA/TestWithVmStatusZoneEmpty (0.00s)
    --- PASS: TestCSINodeTopologyControllerForTKGSHA/TestWithGetVmFailure (0.00s)
PASS
ok  	sigs.k8s.io/vsphere-csi-driver/v2/pkg/syncer/cnsoperator/controller/csinodetopology	0.045s
make[1]: Leaving directory '/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver'
make push-images
make[1]: Entering directory '/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver'
hack/release.sh -p
building gcr.io/cloud-provider-vsphere/csi/ci/driver:a1f073a1 for linux
error: no builder "vsphere-csi-builder-win" found
builder instance not found, safe to proceed
#1 [internal] load build definition from Dockerfile
#1 transferring dockerfile: 3.09kB done
#1 DONE 0.0s

#2 [internal] load .dockerignore
... skipping 93 lines ...
#0 9.415 python3                  x86_64       3.10.0-3.ph4     photon-updates   3.44M 3605256
#0 9.415 ncurses                  x86_64       6.2-6.ph4        photon-updates 363.42k 372138
#0 9.415 expat                    x86_64       2.2.9-9.ph4      photon-updates  31.54k 32296
#0 9.415 pcre                     x86_64       8.44-2.ph4       photon-release 727.69k 745153
#0 9.415 libseccomp               x86_64       2.5.0-2.ph4      photon-release 167.72k 171743
#0 9.415 libmicrohttpd            x86_64       0.9.71-2.ph4     photon-release 148.80k 152368
#0 9.415 libgpg-error             x86_64       1.39-1.ph4       photon-release 223.29k 228654
#0 9.415 libacl                   x86_64       2.2.53-1.ph4     photon-release  39.69k 40642
#0 9.415 kmod                     x86_64       27-1.ph4         photon-release 266.29k 272681
#0 9.415 systemd-rpm-macros       noarch       247.11-2.ph4     photon-updates   5.45k 5581
#0 9.415 systemd-pam              x86_64       247.11-2.ph4     photon-updates 452.89k 463757
#0 9.415 systemd-libs             x86_64       247.11-2.ph4     photon-updates   1.60M 1673900
#0 9.415 elfutils                 x86_64       0.181-4.ph4      photon-updates   3.56M 3728253
... skipping 183 lines ...
#8 28.15 Installing/Updating: libselinux-3.3-1.ph4.x86_64
#8 28.17 Installing/Updating: coreutils-selinux-9.1-1.ph4.x86_64
#8 28.27 Installing/Updating: xz-5.2.5-2.ph4.x86_64
#8 28.29 Installing/Updating: cracklib-2.9.7-2.ph4.x86_64
#8 28.31 using empty dict to provide pw_dict
#8 28.32 Installing/Updating: gc-8.0.4-1.ph4.x86_64
#8 28.35 Installing/Updating: libgpg-error-1.39-1.ph4.x86_64
#8 28.37 Installing/Updating: libgcrypt-1.9.4-1.ph4.x86_64
#8 28.40 Installing/Updating: ncurses-6.2-6.ph4.x86_64
#8 28.41 Installing/Updating: libtirpc-1.2.6-2.ph4.x86_64
#8 28.44 Installing/Updating: libltdl-2.4.6-3.ph4.x86_64
#8 28.46 Installing/Updating: libunistring-0.9.10-1.ph4.x86_64
#8 28.50 Installing/Updating: pkg-config-0.29.2-4.ph4.x86_64
... skipping 192 lines ...
 ---> Running in 6f64981863d0
Removing intermediate container 6f64981863d0
 ---> b536b6d8f549
Successfully built b536b6d8f549
Successfully tagged gcr.io/cloud-provider-vsphere/csi/ci/syncer:a1f073a1
tagging image gcr.io/cloud-provider-vsphere/csi/ci/syncer:a1f073a1 as latest
error: failed to find instance "vsphere-csi-builder-win": open /root/.docker/buildx/instances/vsphere-csi-builder-win: no such file or directory
vsphere-csi-builder-win
building gcr.io/cloud-provider-vsphere/csi/ci/driver:a1f073a1 for windows
#1 [internal] booting buildkit
#1 pulling image moby/buildkit:buildx-stable-1
#1 pulling image moby/buildkit:buildx-stable-1 3.1s done
#1 creating container buildx_buildkit_vsphere-csi-builder-win0
... skipping 227 lines ...
#18 DONE 2.6s
WARNING! Your password will be stored unencrypted in /root/.docker/config.json.
Configure a credential helper to remove this warning. See
https://docs.docker.com/engine/reference/commandline/login/#credentials-store

Login Succeeded
error: failed to find instance "vsphere-csi-builder-win": open /root/.docker/buildx/instances/vsphere-csi-builder-win: no such file or directory
vsphere-csi-builder-win
building gcr.io/cloud-provider-vsphere/csi/ci/driver:a1f073a1 for windows
#1 [internal] booting buildkit
#1 pulling image moby/buildkit:buildx-stable-1 0.1s done
#1 creating container buildx_buildkit_vsphere-csi-builder-win0
#1 creating container buildx_buildkit_vsphere-csi-builder-win0 0.8s done
... skipping 50 lines ...
  49 |     
  50 |     FROM mcr.microsoft.com/windows/nanoserver:${OSVERSION}
  51 | >>> COPY --from=core /Windows/System32/netapi32.dll /Windows/System32/netapi32.dll
  52 |     
  53 |     USER ContainerAdministrator
--------------------
error: failed to solve: failed to compute cache key: failed to copy: httpReadSeeker: failed open: failed to do request: Get "https://centralus.data.mcr.microsoft.com/795a02ce1e3547eb8d4b8a7d06af7541-39qwoxxdjo//docker/registry/v2/blobs/sha256/66/6626f490e738e10ea5e31ff2643e3a8c372e076d9030c77fac37537dbf12b73c/data?se=2022-06-06T18%3A25%3A29Z&sig=2iEHE96HKV%2By3Dn8J9tn7wqrMj%2BE9l2fOkqoN2%2Foizo%3D&sp=r&spr=https&sr=b&sv=2016-05-31&regid=795a02ce1e3547eb8d4b8a7d06af7541": stream error: stream ID 1; CANCEL; received from peer
make[1]: *** [Makefile:416: push-images] Error 1
make[1]: Leaving directory '/home/prow/go/src/sigs.k8s.io/vsphere-csi-driver'
make: *** [Makefile:211: deploy] Error 2