This job view page is being replaced by Spyglass soon. Check out the new job view.
PRk8s-infra-cherrypick-robot: [release-1.0] fix: correct condition message for NodeNetworkUnavailable
Resultsuccess
Tests 0 failed / 0 succeeded
Started2022-09-04 12:00
Elapsed8m12s
Revision
Refs 2229
uploadercrier
uploadercrier

No Test Failures!


Error lines from build-log.txt

... skipping 78 lines ...
=== RUN   TestSendFailureRegionalRetry/RegionalRetry
=== RUN   TestSendFailureRegionalRetry/ReplicationLatency
--- PASS: TestSendFailureRegionalRetry (0.01s)
    --- PASS: TestSendFailureRegionalRetry/RegionalRetry (0.00s)
    --- PASS: TestSendFailureRegionalRetry/ReplicationLatency (0.00s)
=== RUN   TestSendFailure
E0904 12:02:52.812208   14096 azure_armclient.go:157] Send.sendRequest: error in parsing response body string: invalid character 'i' in literal false (expecting 'l'), Skip retrying regional host
--- PASS: TestSendFailure (0.00s)
=== RUN   TestSendThrottled
E0904 12:02:52.813443   14096 azure_armclient.go:157] Send.sendRequest: error in parsing response body string: invalid character 'i' in literal false (expecting 'l'), Skip retrying regional host
--- PASS: TestSendThrottled (0.00s)
=== RUN   TestSendAsync
E0904 12:02:52.814962   14096 azure_armclient.go:157] Send.sendRequest: error in parsing response body string: invalid character 'i' in literal false (expecting 'l'), Skip retrying regional host
--- PASS: TestSendAsync (0.00s)
=== RUN   TestSendAsyncSuccess
--- PASS: TestSendAsyncSuccess (0.07s)
=== RUN   TestNormalizeAzureRegion
--- PASS: TestNormalizeAzureRegion (0.00s)
=== RUN   TestGetResource
... skipping 6 lines ...
    --- PASS: TestGetResource/GetResourceWithExpandQuery (0.00s)
    --- PASS: TestGetResource/GetResourceWithExpandAPIVersionQuery (0.00s)
    --- PASS: TestGetResource/GetResourceWithExpandAPIVersionQuery-empty-expand (0.00s)
=== RUN   TestPutResource
--- PASS: TestPutResource (0.00s)
=== RUN   TestPutResources
E0904 12:02:52.894201   14096 azure_armclient.go:157] Send.sendRequest: error in parsing response body string: unexpected end of JSON input, Skip retrying regional host
--- PASS: TestPutResources (0.00s)
=== RUN   TestPutResourceAsync
E0904 12:02:52.898339   14096 azure_armclient.go:157] Send.sendRequest: error in parsing response body string: invalid character 'i' in literal false (expecting 'l'), Skip retrying regional host
--- PASS: TestPutResourceAsync (0.00s)
=== RUN   TestDeleteResourceAsync
E0904 12:02:52.900863   14096 azure_armclient.go:157] Send.sendRequest: error in parsing response body string: invalid character 'i' in literal false (expecting 'l'), Skip retrying regional host
--- PASS: TestDeleteResourceAsync (0.00s)
=== RUN   TestPatchResource
--- PASS: TestPatchResource (0.00s)
=== RUN   TestPatchResourceAsync
--- PASS: TestPatchResourceAsync (0.00s)
=== RUN   TestPostResource
E0904 12:02:52.932418   14096 azure_armclient.go:157] Send.sendRequest: error in parsing response body string: invalid character 'i' in literal false (expecting 'l'), Skip retrying regional host
--- PASS: TestPostResource (0.03s)
=== RUN   TestDeleteResource
E0904 12:02:52.935416   14096 azure_armclient.go:157] Send.sendRequest: error in parsing response body string: invalid character 'i' in literal false (expecting 'l'), Skip retrying regional host
--- PASS: TestDeleteResource (0.00s)
=== RUN   TestHeadResource
E0904 12:02:52.937911   14096 azure_armclient.go:157] Send.sendRequest: error in parsing response body string: unexpected end of JSON input, Skip retrying regional host
--- PASS: TestHeadResource (0.00s)
=== RUN   TestGetResourceID
=== RUN   TestGetResourceID/resource_ID
=== RUN   TestGetResourceID/resource_list_ID
=== RUN   TestGetResourceID/child_resource_ID
=== RUN   TestGetResourceID/child_resource_list_ID
... skipping 943 lines ...
    --- PASS: TestNodeUpdateRetryTimeout/count_1 (0.00s)
    --- PASS: TestNodeUpdateRetryTimeout/count_2 (0.00s)
    --- PASS: TestNodeUpdateRetryTimeout/count_3 (0.00s)
    --- PASS: TestNodeUpdateRetryTimeout/count_50 (0.00s)
=== RUN   TestNewCloudCIDRAllocator
I0904 12:05:28.955665   21501 cloud_cidr_allocator.go:100] Sending events to api server.
E0904 12:05:28.956558   21501 range_allocator.go:325] Error filtering out service cidr out cluster cidr:10.10.0.0/24 (index:0) 10.10.0.0/25: CIDR: 0.0.0.0/0 is out of the range of CIDR allocator
I0904 12:05:28.956769   21501 cloud_cidr_allocator.go:200] Using cloud CIDR allocator (provider: azure)
--- PASS: TestNewCloudCIDRAllocator (0.00s)
=== RUN   TestUpdateMaxSubnetSizes
=== RUN   TestUpdateMaxSubnetSizes/updateMaxSubnetSizes_should_calculate_the_correct_max_sizes
=== RUN   TestUpdateMaxSubnetSizes/updateMaxSubnetSizes_should_work_with_the_dual_stack_cidrs
--- PASS: TestUpdateMaxSubnetSizes (0.00s)
... skipping 24 lines ...
I0904 12:05:28.965546   21501 range_allocator.go:110] No Service CIDR provided. Skipping filtering out service addresses.
I0904 12:05:28.965621   21501 range_allocator.go:116] No Secondary Service CIDR provided. Skipping filtering out secondary service addresses.
=== RUN   TestOccupyPreExistingCIDR/success,_dual_stack_both_allocated_correctly
I0904 12:05:28.966287   21501 range_allocator.go:82] Sending events to api server.
I0904 12:05:28.966621   21501 range_allocator.go:110] No Service CIDR provided. Skipping filtering out service addresses.
I0904 12:05:28.966672   21501 range_allocator.go:116] No Secondary Service CIDR provided. Skipping filtering out secondary service addresses.
=== RUN   TestOccupyPreExistingCIDR/fail,_single_stack_incorrect_node_allocation
I0904 12:05:28.967253   21501 range_allocator.go:82] Sending events to api server.
I0904 12:05:28.967484   21501 range_allocator.go:110] No Service CIDR provided. Skipping filtering out service addresses.
I0904 12:05:28.967512   21501 range_allocator.go:116] No Secondary Service CIDR provided. Skipping filtering out secondary service addresses.
=== RUN   TestOccupyPreExistingCIDR/fail,_dualstack_node_allocating_from_non_existing_cidr
I0904 12:05:28.967886   21501 range_allocator.go:82] Sending events to api server.
I0904 12:05:28.968021   21501 range_allocator.go:110] No Service CIDR provided. Skipping filtering out service addresses.
I0904 12:05:28.968049   21501 range_allocator.go:116] No Secondary Service CIDR provided. Skipping filtering out secondary service addresses.
=== RUN   TestOccupyPreExistingCIDR/fail,_dualstack_node_allocating_bad_v4
I0904 12:05:28.968340   21501 range_allocator.go:82] Sending events to api server.
I0904 12:05:28.969945   21501 range_allocator.go:110] No Service CIDR provided. Skipping filtering out service addresses.
I0904 12:05:28.970011   21501 range_allocator.go:116] No Secondary Service CIDR provided. Skipping filtering out secondary service addresses.
=== RUN   TestOccupyPreExistingCIDR/fail,_dualstack_node_allocating_bad_v6
I0904 12:05:28.970615   21501 range_allocator.go:82] Sending events to api server.
I0904 12:05:28.970872   21501 range_allocator.go:110] No Service CIDR provided. Skipping filtering out service addresses.
I0904 12:05:28.970909   21501 range_allocator.go:116] No Secondary Service CIDR provided. Skipping filtering out secondary service addresses.
--- PASS: TestOccupyPreExistingCIDR (0.01s)
    --- PASS: TestOccupyPreExistingCIDR/success,_single_stack_no_node_allocation (0.00s)
    --- PASS: TestOccupyPreExistingCIDR/success,_dual_stack_no_node_allocation (0.00s)
    --- PASS: TestOccupyPreExistingCIDR/success,_single_stack_correct_node_allocation (0.00s)
    --- PASS: TestOccupyPreExistingCIDR/success,_dual_stack_both_allocated_correctly (0.00s)
    --- PASS: TestOccupyPreExistingCIDR/fail,_single_stack_incorrect_node_allocation (0.00s)
    --- PASS: TestOccupyPreExistingCIDR/fail,_dualstack_node_allocating_from_non_existing_cidr (0.00s)
    --- PASS: TestOccupyPreExistingCIDR/fail,_dualstack_node_allocating_bad_v4 (0.00s)
    --- PASS: TestOccupyPreExistingCIDR/fail,_dualstack_node_allocating_bad_v6 (0.00s)
=== RUN   TestAllocateOrOccupyCIDRSuccess
I0904 12:05:28.971575   21501 range_allocator.go:82] Sending events to api server.
I0904 12:05:28.971949   21501 range_allocator.go:110] No Service CIDR provided. Skipping filtering out service addresses.
I0904 12:05:28.972058   21501 range_allocator.go:116] No Secondary Service CIDR provided. Skipping filtering out secondary service addresses.
I0904 12:05:28.972260   21501 range_allocator.go:172] Starting range CIDR allocator
I0904 12:05:28.972370   21501 shared_informer.go:240] Waiting for caches to sync for cidrallocator
... skipping 225 lines ...
--- PASS: TestGetPrivateIPsForMachine (0.00s)
=== RUN   TestGetIPForMachineWithRetry
W0904 12:05:56.825218   22299 azure_wrap.go:77] Unable to find node vm: instance not found
E0904 12:05:56.825286   22299 azure_backoff.go:141] GetIPForMachineWithRetry(vm): backoff failure, will retry,err=instance not found
--- PASS: TestGetIPForMachineWithRetry (0.00s)
=== RUN   TestCreateOrUpdateSecurityGroupCanceled
W0904 12:05:56.825985   22299 azure_backoff.go:164] CreateOrUpdateSecurityGroup(sg) failed: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 0, RawError: canceledandsupersededduetoanotheroperation, NSG request: {}
--- PASS: TestCreateOrUpdateSecurityGroupCanceled (0.00s)
=== RUN   TestCreateOrUpdateLB
W0904 12:05:56.826803   22299 azure_backoff.go:225] LoadBalancerClient.CreateOrUpdate(lb) failed: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 412, RawError: %!w(<nil>), LoadBalancer request: {}
W0904 12:05:56.827323   22299 azure_backoff.go:225] LoadBalancerClient.CreateOrUpdate(lb) failed: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 0, RawError: canceledandsupersededduetoanotheroperation, LoadBalancer request: {}
W0904 12:05:56.828130   22299 azure_backoff.go:225] LoadBalancerClient.CreateOrUpdate(lb) failed: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 0, RawError: Code="ReferencedResourceNotProvisioned" Message="Cannot proceed with operation because resource /subscriptions/sub/resourceGroups/rg/providers/Microsoft.Network/publicIPAddresses/pip used by resource /subscriptions/sub/resourceGroups/rg/providers/Microsoft.Network/loadBalancers/lb is not in Succeeded state. Resource is in Failed state and the last operation that updated/is updating the resource is PutPublicIpAddressOperation.", LoadBalancer request: {}
--- PASS: TestCreateOrUpdateLB (0.00s)
=== RUN   TestListAgentPoolLBs
E0904 12:05:56.830569   22299 azure_backoff.go:322] LoadBalancerClient.List(rg) failure with err=&{false 500 0001-01-01 00:00:00 +0000 UTC <nil>}
W0904 12:05:56.830864   22299 azure_backoff.go:277] ListManagedLBs: no LBs found
--- PASS: TestListAgentPoolLBs (0.00s)
=== RUN   TestListPIP
E0904 12:05:56.831739   22299 azure_backoff.go:340] PublicIPAddressesClient.List(rg) failure with err=&{false 500 0001-01-01 00:00:00 +0000 UTC <nil>}
--- PASS: TestListPIP (0.00s)
=== RUN   TestCreateOrUpdatePIP
W0904 12:05:56.832472   22299 azure_backoff.go:362] PublicIPAddressesClient.CreateOrUpdate(rg, nic) failed: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 412, RawError: %!w(<nil>), PublicIP request: {}
W0904 12:05:56.832863   22299 azure_backoff.go:362] PublicIPAddressesClient.CreateOrUpdate(rg, nic) failed: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 0, RawError: canceledandsupersededduetoanotheroperation, PublicIP request: {}
W0904 12:05:56.833204   22299 azure_backoff.go:362] PublicIPAddressesClient.CreateOrUpdate(rg, nic) failed: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 500, RawError: %!w(<nil>), PublicIP request: {}
--- PASS: TestCreateOrUpdatePIP (0.00s)
=== RUN   TestCreateOrUpdateInterface
E0904 12:05:56.833681   22299 azure_backoff.go:389] InterfacesClient.CreateOrUpdate(nic) failed: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 500, RawError: %!w(<nil>)
--- PASS: TestCreateOrUpdateInterface (0.00s)
=== RUN   TestDeletePublicIP
E0904 12:05:56.834178   22299 azure_backoff.go:404] PublicIPAddressesClient.Delete(pip) failed: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 500, RawError: %!w(<nil>)
--- PASS: TestDeletePublicIP (0.00s)
=== RUN   TestDeleteLB
E0904 12:05:56.834688   22299 azure_backoff.go:432] LoadBalancerClient.Delete(lb) failed: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 500, RawError: %!w(<nil>)
--- PASS: TestDeleteLB (0.00s)
=== RUN   TestCreateOrUpdateRouteTable
W0904 12:05:56.835267   22299 azure_backoff.go:450] RouteTablesClient.CreateOrUpdate(rt) failed: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 412, RawError: %!w(<nil>), RouteTable request: {}
E0904 12:05:56.835348   22299 azure_backoff.go:462] RouteTablesClient.CreateOrUpdate(rt) failed: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 412, RawError: %!w(<nil>)
W0904 12:05:56.835545   22299 azure_backoff.go:450] RouteTablesClient.CreateOrUpdate(rt) failed: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 0, RawError: canceledandsupersededduetoanotheroperation, RouteTable request: {}
E0904 12:05:56.835618   22299 azure_backoff.go:462] RouteTablesClient.CreateOrUpdate(rt) failed: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 0, RawError: canceledandsupersededduetoanotheroperation
--- PASS: TestCreateOrUpdateRouteTable (0.00s)
=== RUN   TestCreateOrUpdateRoute
--- PASS: TestCreateOrUpdateRoute (0.00s)
=== RUN   TestDeleteRouteWithName
E0904 12:05:56.836612   22299 azure_backoff.go:501] RoutesClient.Delete(rt, rt) failed: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 500, RawError: %!w(<nil>)
--- PASS: TestDeleteRouteWithName (0.00s)
=== RUN   TestCreateOrUpdateVMSS
E0904 12:05:56.836946   22299 azure_backoff.go:515] CreateOrUpdateVMSS: error getting vmss(vmss): &{false 500 0001-01-01 00:00:00 +0000 UTC <nil>}
E0904 12:05:56.837085   22299 azure_backoff.go:515] CreateOrUpdateVMSS: error getting vmss(vmss): &{false 429 0001-01-01 00:00:00 +0000 UTC <nil>}
E0904 12:05:56.837214   22299 azure_backoff.go:515] CreateOrUpdateVMSS: error getting vmss(vmss): &{false 0 0001-01-01 00:00:00 +0000 UTC azure cloud provider rate limited(write) for operation CreateOrUpdate}
--- PASS: TestCreateOrUpdateVMSS (0.00s)
=== RUN   TestRequestBackoff
--- PASS: TestRequestBackoff (0.00s)
=== RUN   TestInitStorageAccounts
E0904 12:05:56.837731   22299 azure_blobDiskController.go:73] azureDisk - getAllStorageAccounts error: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 500, RawError: %!w(<nil>)
I0904 12:05:56.837812   22299 azure_blobDiskController.go:465] azureDisk - identified account ds-0 as part of shared PVC accounts
--- PASS: TestInitStorageAccounts (0.00s)
=== RUN   TestCreateVolume
--- PASS: TestCreateVolume (0.97s)
=== RUN   TestDeleteVolume
W0904 12:05:58.123745   22299 azure_blobDiskController.go:126] azureDisk - failed to delete blob https://foo.blob./vhds/bar.vhd err: %!w(storage.AzureStorageServiceError={AccountIsDisabled The specified account is disabled.
RequestId:f6f94167-c01e-0069-3e56-c06e7d000000
Time:2022-09-04T12:05:58.1024308Z      403 f6f94167-c01e-0069-3e56-c06e7d000000 Sun, 04 Sep 2022 12:05:58 GMT })
--- PASS: TestDeleteVolume (0.32s)
=== RUN   TestCreateVHDBlobDisk
--- PASS: TestCreateVHDBlobDisk (0.18s)
=== RUN   TestGetAllStorageAccounts
... skipping 23 lines ...
    --- PASS: TestGetConfigFromSecret/Error_should_be_reported_when_secret_doesn't_exists (0.00s)
    --- PASS: TestGetConfigFromSecret/Error_should_be_reported_when_secret_exists_but_cloud-config_data_is_not_provided (0.00s)
    --- PASS: TestGetConfigFromSecret/Error_should_be_reported_when_it_failed_to_parse_Azure_cloud-config (0.00s)
=== RUN   TestInitializeCloudFromSecret
=== RUN   TestInitializeCloudFromSecret/Azure_config_shouldn't_be_override_when_cloud_config_type_is_file
=== RUN   TestInitializeCloudFromSecret/Azure_config_shouldn't_be_override_when_cloud_config_type_is_unknown
E0904 12:08:36.161957   22299 azure_config.go:55] Failed to initialize Azure cloud provider: cloudConfigType UnknownConfigType is not supported, supported values are [file merge secret]
=== RUN   TestInitializeCloudFromSecret/Azure_config_should_be_override_when_cloud_config_type_is_secret
=== RUN   TestInitializeCloudFromSecret/Azure_config_should_be_override_when_cloud_config_type_is_merge
=== RUN   TestInitializeCloudFromSecret/Error_should_be_reported_when_secret_doesn't_exists
E0904 12:08:36.168621   22299 azure_config.go:45] Failed to get cloud-config from secret: failed to get secret kube-system/azure-cloud-provider: secrets "azure-cloud-provider" not found
=== RUN   TestInitializeCloudFromSecret/Error_should_be_reported_when_secret_exists_but_cloud-config_data_is_not_provided
E0904 12:08:36.169117   22299 azure_config.go:45] Failed to get cloud-config from secret: cloud-config is not set in the secret (kube-system/azure-cloud-provider)
--- PASS: TestInitializeCloudFromSecret (0.01s)
    --- PASS: TestInitializeCloudFromSecret/Azure_config_shouldn't_be_override_when_cloud_config_type_is_file (0.00s)
    --- PASS: TestInitializeCloudFromSecret/Azure_config_shouldn't_be_override_when_cloud_config_type_is_unknown (0.00s)
    --- PASS: TestInitializeCloudFromSecret/Azure_config_should_be_override_when_cloud_config_type_is_secret (0.00s)
    --- PASS: TestInitializeCloudFromSecret/Azure_config_should_be_override_when_cloud_config_type_is_merge (0.00s)
    --- PASS: TestInitializeCloudFromSecret/Error_should_be_reported_when_secret_doesn't_exists (0.00s)
    --- PASS: TestInitializeCloudFromSecret/Error_should_be_reported_when_secret_exists_but_cloud-config_data_is_not_provided (0.00s)
=== RUN   TestCommonAttachDisk
W0904 12:08:36.169871   22299 azure_wrap.go:77] Unable to find node vm1: instance not found
E0904 12:08:36.169992   22299 azure_controller_common.go:494] error of getting data disks for node "vm1": instance not found
W0904 12:08:36.170654   22299 azure_controller_common.go:197] size of disk(/subscriptions/subscription/resourceGroups/rg/providers/Microsoft.Compute/disks/disk-name) is 4096GB which is bigger than limit(4096GB), set cacheMode as None
W0904 12:08:36.171125   22299 azure_controller_common.go:197] size of disk(/subscriptions/subscription/resourceGroups/rg/providers/Microsoft.Compute/disks/disk-name) is 4096GB which is bigger than limit(4096GB), set cacheMode as None
W0904 12:08:36.171713   22299 azure_controller_common.go:176] volume "/subscriptions/subscription/resourceGroups/rg/providers/Microsoft.Compute/disks/disk-name" is actually attached to current node "vm1", invalidate vm cache and return error
--- PASS: TestCommonAttachDisk (0.00s)
=== RUN   TestCommonAttachDiskWithVMSS
E0904 12:08:36.172922   22299 azure_controller_common.go:494] error of getting data disks for node "vm1": error of converting vmSet (&{%!q(*provider.Cloud=&{{{ tenant     false  subscription    } {{false 0 0 0 0} <nil> <nil> <nil> <nil> <nil> <nil> <nil> <nil> <nil> <nil> <nil> <nil> <nil> <nil>}  rg westus   vnet rg subnet nsg rg rt rg as vmss vmss  map[]      false false false false false  0 0 <nil> <nil> 250 0 0 0 0 0 60 120 120 120 120 600 120 0 0 rg} {  } {                              {            }} 0xc0007bd530 0xc0007bd560 0xc0007bd500 0xc0007bd540 0xc0007bd510 0xc0007bd520 0xc0007bd550 0xc0007bd590 <nil> 0xc0007bd4f0 <nil> <nil> 0xc0007bd570 0xc0007bd580 <nil> <nil> <nil> 0xc0007bd5a0 {0 0 0 0 0} <nil> 0xc0007bd5b0 false false {{0 0} 0 0 0 0} map[] map[] map[] map[] map[] 0x20f7ac0 {0 0} map[] map[westus:[1 2 3]] {{0 0} 0 0 0 0} <nil> <nil> 0xc0007bd4e0 <nil> 0xc00056a360 0xc00056a450 0xc00056a540 0xc00056a630 0xc00056a720 0xc00056a810 <nil> 0xc000518760 0xc0007cd110}) %!q(*cache.TimedCache=&{0xc0007b69f0 {0 0} 0x2161e20 600000000000})}) to ScaleSet with vmType "vmss"
E0904 12:08:36.173101   22299 azure_controller_common.go:494] error of getting data disks for node "vmss1": not a vmss instance
--- PASS: TestCommonAttachDiskWithVMSS (0.00s)
=== RUN   TestCommonDetachDisk
W0904 12:08:36.173470   22299 azure_wrap.go:77] Unable to find node vm1: instance not found
W0904 12:08:36.173513   22299 azure_standard.go:523] Unable to find node vm1: instance not found
W0904 12:08:36.173534   22299 azure_controller_common.go:332] azureDisk - failed to get azure instance id("vm1"), DetachDisk(/subscriptions/subscription/resourceGroups/rg/providers/Microsoft.Compute/disks/disk-name) will assume disk is already detached
E0904 12:08:36.174020   22299 azure_controller_standard.go:183] detach azure disk on node(vm1): disk list(map[/subscriptions/subscription/resourcegroups/rg/providers/microsoft.compute/disks/disk-name:disk2]) not found
--- PASS: TestCommonDetachDisk (0.00s)
=== RUN   TestCommonUpdateVM
--- PASS: TestCommonUpdateVM (0.00s)
=== RUN   TestGetDiskLun
--- PASS: TestGetDiskLun (0.00s)
... skipping 12 lines ...
=== RUN   TestFilterNonExistingDisks
E0904 12:08:36.179242   22299 azure_controller_common.go:616] disk(/subscriptions/subscription/resourceGroups/rg/providers/Microsoft.Compute/disks/DiskName2) does not exist, removed from data disk list
E0904 12:08:36.179360   22299 azure_controller_common.go:616] disk(/subscriptions/subscription/resourceGroups/rg/providers/Microsoft.Compute/disks/DiskName3) does not exist, removed from data disk list
E0904 12:08:36.179687   22299 azure_controller_common.go:616] disk(/subscriptions/subscription/resourceGroups/rg/providers/Microsoft.Compute/disks/DiskName4) does not exist, removed from data disk list
--- PASS: TestFilterNonExistingDisks (0.00s)
=== RUN   TestFilterNonExistingDisksWithSpecialHTTPStatusCode
E0904 12:08:36.180086   22299 azure_controller_common.go:611] checkDiskExists(/subscriptions/subscription/resourceGroups/rg/providers/Microsoft.Compute/disks/specialdisk) failed with error: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 400, RawError: instance not found
--- PASS: TestFilterNonExistingDisksWithSpecialHTTPStatusCode (0.00s)
=== RUN   TestIsInstanceNotFoundError
--- PASS: TestIsInstanceNotFoundError (0.00s)
=== RUN   TestAttachDiskRequestFuncs
--- PASS: TestAttachDiskRequestFuncs (0.00s)
=== RUN   TestDetachDiskRequestFuncs
--- PASS: TestDetachDiskRequestFuncs (0.00s)
=== RUN   TestStandardAttachDisk
W0904 12:08:36.182318   22299 azure_wrap.go:77] Unable to find node vm2: instance not found
E0904 12:08:36.182989   22299 azure_controller_standard.go:121] azureDisk - attach disk list(map[uri:%!s(*provider.AttachDiskOptions=&{ReadOnly  DiskEncryptionSetID true false 0})]) on rg(rg) vm(vm1) failed, err: &{false 404 0001-01-01 00:00:00 +0000 UTC instance not found}
E0904 12:08:36.183093   22299 azure_controller_standard.go:123] azureDisk - begin to filterNonExistingDisks(map[uri:0xc000402240]) on rg(rg) vm(vm1)
E0904 12:08:36.183129   22299 azure_controller_common.go:611] checkDiskExists(uri) failed with error: invalid disk URI: uri
--- PASS: TestStandardAttachDisk (0.00s)
=== RUN   TestStandardDetachDisk
W0904 12:08:36.184178   22299 azure_wrap.go:77] Unable to find node vm2: instance not found
W0904 12:08:36.184226   22299 azure_controller_standard.go:150] azureDisk - cannot find node vm2, skip detaching disk list(map[uri:])
E0904 12:08:36.184663   22299 azure_controller_standard.go:183] detach azure disk on node(vm1): disk list(map[uri:disk2]) not found
E0904 12:08:36.185680   22299 azure_controller_standard.go:183] detach azure disk on node(vm1): disk list(map[uri:]) not found
E0904 12:08:36.185746   22299 azure_controller_standard.go:204] azureDisk - detach disk list(map[uri:]) on rg(rg) vm(vm1) failed, err: &{false 404 0001-01-01 00:00:00 +0000 UTC instance not found}
E0904 12:08:36.185826   22299 azure_controller_standard.go:206] azureDisk - begin to filterNonExistingDisks(map[uri:]) on rg(rg) vm(vm1)
--- PASS: TestStandardDetachDisk (0.00s)
=== RUN   TestStandardUpdateVM
--- PASS: TestStandardUpdateVM (0.00s)
=== RUN   TestGetDataDisks
W0904 12:08:36.187336   22299 azure_wrap.go:77] Unable to find node vm2: instance not found
--- PASS: TestGetDataDisks (2.00s)
=== RUN   TestAttachDiskWithVMSS
E0904 12:08:38.191212   22299 azure_controller_vmss.go:125] azureDisk - attach disk list(map[/subscriptions/subscription/resourceGroups/rg/providers/Microsoft.Compute/disks/disk-name:%!s(*provider.AttachDiskOptions=&{ReadWrite disk-name  false true 0})]) on rg(rg) vm(vmss00-vm-000000) failed, err: &{false 404 0001-01-01 00:00:00 +0000 UTC instance not found}
E0904 12:08:38.191356   22299 azure_controller_vmss.go:127] azureDisk - begin to filterNonExistingDisks(map[/subscriptions/subscription/resourceGroups/rg/providers/Microsoft.Compute/disks/disk-name:0xc00070c980]) on rg(rg) vm(vmss00-vm-000000)
--- PASS: TestAttachDiskWithVMSS (0.00s)
=== RUN   TestDetachDiskWithVMSS
E0904 12:08:38.192905   22299 azure_controller_vmss.go:209] azureDisk - detach disk list(map[disk-name:disk-name]) on rg(rg) vm(vmss00-vm-000000) failed, err: &{false 404 0001-01-01 00:00:00 +0000 UTC instance not found}
E0904 12:08:38.192992   22299 azure_controller_vmss.go:211] azureDisk - begin to filterNonExistingDisks(map[disk-name:disk-name]) on rg(rg) vm(vmss00-vm-000000)
E0904 12:08:38.193414   22299 azure_controller_vmss.go:187] detach azure disk on node(vmss00-vm-000000): disk list(map[disk-name:disk-name-err]) not found
--- PASS: TestDetachDiskWithVMSS (0.00s)
=== RUN   TestUpdateVMWithVMSS
--- PASS: TestUpdateVMWithVMSS (0.00s)
=== RUN   TestGetDataDisksWithVMSS
... skipping 14 lines ...
E0904 12:08:38.241263   22299 azure_backoff.go:141] GetIPForMachineWithRetry(vm2): backoff failure, will retry,err=instance not found
--- PASS: TestNodeAddresses (0.03s)
=== RUN   TestInstanceExistsByProviderID
W0904 12:08:38.253154   22299 azure_wrap.go:77] Unable to find node vm3: instance not found
W0904 12:08:38.253207   22299 azure_standard.go:523] Unable to find node vm3: instance not found
E0904 12:08:38.255518   22299 azure_vmss.go:394] Unable to find node by providerID azure:///subscriptions/script/resourceGroups/rg/providers/Microsoft.Compute/virtualMachineScaleSets/vmssee6c2/virtualMachines/0: instance not found
E0904 12:08:38.256273   22299 azure_vmss.go:728] VirtualMachineScaleSetVMsClient.List(rg, missing-vmss) failed: &{false 404 0001-01-01 00:00:00 +0000 UTC <nil>}
E0904 12:08:38.256341   22299 azure_vmss.go:394] Unable to find node by providerID azure:///subscriptions/script/resourceGroups/rg/providers/Microsoft.Compute/virtualMachineScaleSets/missing-vmss/virtualMachines/0: instance not found
--- PASS: TestInstanceExistsByProviderID (0.00s)
=== RUN   TestNodeAddressesByProviderID
--- PASS: TestNodeAddressesByProviderID (0.01s)
=== RUN   TestCurrentNodeName
--- PASS: TestCurrentNodeName (0.00s)
... skipping 11 lines ...
--- PASS: TestFindProbe (0.00s)
=== RUN   TestFindRule
--- PASS: TestFindRule (0.00s)
=== RUN   TestSubnet
--- PASS: TestSubnet (0.00s)
=== RUN   TestEnsureLoadBalancerDeleted
E0904 12:08:38.282743   22299 azure_loadbalancer.go:94] reconcileLoadBalancer(default/service4) failed: findMatchedPIPByLoadBalancerIP: cannot find public IP with IP address 1.2.3.4 in resource group random-rg
E0904 12:08:38.283687   22299 azure_loadbalancer.go:94] reconcileLoadBalancer(default/service5) failed: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 404, RawError: instance not found
W0904 12:08:38.284022   22299 azure_backoff.go:277] ListManagedLBs: no LBs found
--- PASS: TestEnsureLoadBalancerDeleted (0.02s)
=== RUN   TestServiceOwnsPublicIP
=== RUN   TestServiceOwnsPublicIP/false_should_be_returned_when_pip_is_nil
W0904 12:08:38.284535   22299 azure_loadbalancer.go:3441] serviceOwnsPublicIP: nil service or public IP
=== RUN   TestServiceOwnsPublicIP/false_should_be_returned_when_service_name_tag_doesn't_match
... skipping 119 lines ...
=== RUN   TestCleanupVMSetFromBackendPoolForInstanceNotFound
E0904 12:08:38.342700   22299 azure_standard.go:1168] Unable to get the virtual machine by node name k8s-agentpool1-00000000-1: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 0, RawError: instance not found
--- PASS: TestCleanupVMSetFromBackendPoolForInstanceNotFound (0.00s)
=== RUN   TestEnsurePIPTagged
=== RUN   TestEnsurePIPTagged/ensurePIPTagged_should_ensure_the_pip_is_tagged_as_configured
W0904 12:08:38.344436   22299 azure_utils.go:115] parseTags: empty key, ignoring this key-value pair
W0904 12:08:38.344479   22299 azure_utils.go:110] parseTags: error when parsing key-value pair ghi, would ignore this one
=== RUN   TestEnsurePIPTagged/ensurePIPTagged_should_delete_the_old_tags_if_the_SystemTags_is_set
W0904 12:08:38.344732   22299 azure_utils.go:115] parseTags: empty key, ignoring this key-value pair
W0904 12:08:38.344772   22299 azure_utils.go:110] parseTags: error when parsing key-value pair ghi, would ignore this one
=== RUN   TestEnsurePIPTagged/ensurePIPTagged_should_support_TagsMap
W0904 12:08:38.345197   22299 azure_utils.go:115] parseTags: empty key, ignoring this key-value pair
W0904 12:08:38.345245   22299 azure_utils.go:110] parseTags: error when parsing key-value pair ghi, would ignore this one
--- PASS: TestEnsurePIPTagged (0.00s)
    --- PASS: TestEnsurePIPTagged/ensurePIPTagged_should_ensure_the_pip_is_tagged_as_configured (0.00s)
    --- PASS: TestEnsurePIPTagged/ensurePIPTagged_should_delete_the_old_tags_if_the_SystemTags_is_set (0.00s)
    --- PASS: TestEnsurePIPTagged/ensurePIPTagged_should_support_TagsMap (0.00s)
=== RUN   TestEnsureLoadBalancerTagged
=== RUN   TestEnsureLoadBalancerTagged/ensureLoadBalancerTagged_should_not_delete_the_old_tags_if_SystemTags_is_not_specified
... skipping 16 lines ...
=== RUN   TestRemoveFrontendIPConfigurationFromLoadBalancerUpdate
=== RUN   TestRemoveFrontendIPConfigurationFromLoadBalancerUpdate/removeFrontendIPConfigurationFromLoadBalancer_should_remove_the_unwanted_frontend_IP_configuration_and_update_the_LB_if_there_are_remaining_frontend_IP_configurations
--- PASS: TestRemoveFrontendIPConfigurationFromLoadBalancerUpdate (0.00s)
    --- PASS: TestRemoveFrontendIPConfigurationFromLoadBalancerUpdate/removeFrontendIPConfigurationFromLoadBalancer_should_remove_the_unwanted_frontend_IP_configuration_and_update_the_LB_if_there_are_remaining_frontend_IP_configurations (0.00s)
=== RUN   TestCleanOrphanedLoadBalancerLBInUseByVMSS
=== RUN   TestCleanOrphanedLoadBalancerLBInUseByVMSS/cleanOrphanedLoadBalancer_should_retry_deleting_lb_when_meeting_LoadBalancerInUseByVirtualMachineScaleSet
E0904 12:08:38.348607   22299 azure_backoff.go:432] LoadBalancerClient.Delete(test) failed: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 0, RawError: {
	"error": {
    	"code": "LoadBalancerInUseByVirtualMachineScaleSet",
    	"message": "Cannot delete load balancer /subscriptions/sub/resourceGroups/rg/providers/Microsoft.Network/loadBalancers/lb since its child resources lb are in use by virtual machine scale set /subscriptions/sub/resourceGroups/rg/providers/Microsoft.Compute/virtualMachineScaleSets/vmss.",
    	"details": []
  	}
}
W0904 12:08:38.348705   22299 azure_loadbalancer.go:511] cleanOrphanedLoadBalancer(test, default/test, test): failed to DeleteLB: &{false 0 0001-01-01 00:00:00 +0000 UTC {
	"error": {
    	"code": "LoadBalancerInUseByVirtualMachineScaleSet",
    	"message": "Cannot delete load balancer /subscriptions/sub/resourceGroups/rg/providers/Microsoft.Network/loadBalancers/lb since its child resources lb are in use by virtual machine scale set /subscriptions/sub/resourceGroups/rg/providers/Microsoft.Compute/virtualMachineScaleSets/vmss.",
    	"details": []
  	}
}}
=== RUN   TestCleanOrphanedLoadBalancerLBInUseByVMSS/cleanupOrphanedLoadBalancer_should_not_call_delete_api_if_the_lb_does_not_exist
--- PASS: TestCleanOrphanedLoadBalancerLBInUseByVMSS (0.00s)
    --- PASS: TestCleanOrphanedLoadBalancerLBInUseByVMSS/cleanOrphanedLoadBalancer_should_retry_deleting_lb_when_meeting_LoadBalancerInUseByVirtualMachineScaleSet (0.00s)
    --- PASS: TestCleanOrphanedLoadBalancerLBInUseByVMSS/cleanupOrphanedLoadBalancer_should_not_call_delete_api_if_the_lb_does_not_exist (0.00s)
=== RUN   TestReconcileZonesForFrontendIPConfigs
=== RUN   TestReconcileZonesForFrontendIPConfigs/reconcileFrontendIPConfigs_should_reconcile_the_zones_for_the_new_fip_config
=== RUN   TestReconcileZonesForFrontendIPConfigs/reconcileFrontendIPConfigs_should_reconcile_the_zones_for_the_new_internal_fip_config
=== RUN   TestReconcileZonesForFrontendIPConfigs/reconcileFrontendIPConfigs_should_report_an_error_if_failed_to_get_zones
E0904 12:08:38.352944   22299 azure_zones.go:93] getRegionZonesMapWrapper: failed to fetch zones information: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 0, RawError: get zone failed
E0904 12:08:38.353025   22299 azure_loadbalancer.go:1922] reconcileLoadBalancer for service (default/test)(true): failed to getFrontendZones: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 0, RawError: get zone failed
=== RUN   TestReconcileZonesForFrontendIPConfigs/reconcileFrontendIPConfigs_should_use_the_nil_zones_of_the_existing_frontend
=== RUN   TestReconcileZonesForFrontendIPConfigs/reconcileFrontendIPConfigs_should_use_the_non-nil_zones_of_the_existing_frontend
=== RUN   TestReconcileZonesForFrontendIPConfigs/reconcileFrontendIPConfigs_should_reuse_the_existing_private_IP_for_internal_services
--- PASS: TestReconcileZonesForFrontendIPConfigs (0.00s)
    --- PASS: TestReconcileZonesForFrontendIPConfigs/reconcileFrontendIPConfigs_should_reconcile_the_zones_for_the_new_fip_config (0.00s)
    --- PASS: TestReconcileZonesForFrontendIPConfigs/reconcileFrontendIPConfigs_should_reconcile_the_zones_for_the_new_internal_fip_config (0.00s)
... skipping 20 lines ...
--- PASS: TestDeleteManagedDisk (0.00s)
=== RUN   TestGetDisk
--- PASS: TestGetDisk (0.00s)
=== RUN   TestResizeDisk
--- PASS: TestResizeDisk (0.00s)
=== RUN   TestGetLabelsForVolume
E0904 12:08:38.360589   22299 azure_managedDiskController.go:396] Failed to get information for AzureDisk "fakeGetDiskFailed": &{false 0 0001-01-01 00:00:00 +0000 UTC Get Disk failed}
E0904 12:08:38.360768   22299 azure_managedDiskController.go:380] Failed to get resource group for AzureDisk "invalidDiskURI": invalid disk URI: invalidDiskURI
--- PASS: TestGetLabelsForVolume (0.00s)
=== RUN   TestReconcilePrivateLinkService
--- PASS: TestReconcilePrivateLinkService (0.00s)
=== RUN   TestDisablePLSNetworkPolicy
--- PASS: TestDisablePLSNetworkPolicy (0.00s)
=== RUN   TestSafeDeletePLS
... skipping 62 lines ...
--- PASS: TestInitializeCloudProviderRateLimitConfig (0.00s)
=== RUN   TestDeleteRoute
--- PASS: TestDeleteRoute (0.10s)
=== RUN   TestDeleteRouteDualStack
--- PASS: TestDeleteRouteDualStack (0.20s)
=== RUN   TestCreateRoute
E0904 12:08:38.781214   22299 azure_routes.go:130] getRouteTable() failed with error: Route table name is not configured
E0904 12:08:38.781312   22299 azure_routes.go:438] CreateRoute failed for node "node" with error: Route table name is not configured
W0904 12:08:38.982773   22299 azure_backoff.go:450] RouteTablesClient.CreateOrUpdate(rt2) failed: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 500, RawError: CreateOrUpdate error, RouteTable request: {"location":"location","properties":{"routes":[{"name":"node","properties":{"addressPrefix":"1.2.3.4/24","nextHopIpAddress":"2.4.6.8","nextHopType":"VirtualAppliance"}}]}}
E0904 12:08:38.983383   22299 azure_backoff.go:462] RouteTablesClient.CreateOrUpdate(rt2) failed: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 500, RawError: CreateOrUpdate error
E0904 12:08:38.983538   22299 azure_routes.go:207] CreateOrUpdateRouteTable() failed with error: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 500, RawError: CreateOrUpdate error
E0904 12:08:38.983736   22299 azure_routes.go:438] CreateRoute failed for node "node" with error: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 500, RawError: CreateOrUpdate error
W0904 12:08:39.181822   22299 azure_backoff.go:450] RouteTablesClient.CreateOrUpdate(rt4) failed: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 500, RawError: CreateOrUpdate error, RouteTable request: {"location":"location","properties":{}}
E0904 12:08:39.181946   22299 azure_backoff.go:462] RouteTablesClient.CreateOrUpdate(rt4) failed: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 500, RawError: CreateOrUpdate error
E0904 12:08:39.182021   22299 azure_routes.go:138] createRouteTable() failed with error: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 500, RawError: CreateOrUpdate error
E0904 12:08:39.182099   22299 azure_routes.go:438] CreateRoute failed for node "node" with error: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 500, RawError: CreateOrUpdate error
E0904 12:08:39.281995   22299 azure_routes.go:144] getRouteTable() failed with error: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 500, RawError: Get error
E0904 12:08:39.282253   22299 azure_routes.go:438] CreateRoute failed for node "node" with error: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 500, RawError: Get error
E0904 12:08:39.381607   22299 azure_routes.go:130] getRouteTable() failed with error: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 500, RawError: Get error
E0904 12:08:39.381871   22299 azure_routes.go:438] CreateRoute failed for node "node" with error: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 500, RawError: Get error
E0904 12:08:39.382442   22299 azure_backoff.go:141] GetIPForMachineWithRetry(node): backoff failure, will retry,err=getIP error
--- PASS: TestCreateRoute (0.80s)
=== RUN   TestCreateRouteTable
--- PASS: TestCreateRouteTable (0.00s)
=== RUN   TestProcessRoutes
--- PASS: TestProcessRoutes (0.00s)
=== RUN   TestFindFirstIPByFamily
... skipping 54 lines ...
--- PASS: TestGetIPConfigByIPFamily (0.00s)
=== RUN   TestGetBackendPoolName
--- PASS: TestGetBackendPoolName (0.00s)
=== RUN   TestGetStandardInstanceIDByNodeName
W0904 12:08:39.488860   22299 azure_wrap.go:77] Unable to find node vm2: instance not found
W0904 12:08:39.488911   22299 azure_standard.go:523] Unable to find node vm2: instance not found
E0904 12:08:39.489824   22299 azure_standard.go:542] convertResourceGroupNameToLower failed with error: "/subscriptions/subscription/resourceGroups/rg/Microsoft.Compute/virtualMachines/vm4" isn't in Azure resource ID format ".*/subscriptions/(?:.*)/resourceGroups/(.+)/providers/(?:.*)"
--- PASS: TestGetStandardInstanceIDByNodeName (0.00s)
=== RUN   TestGetStandardVMPowerStatusByNodeName
W0904 12:08:39.490239   22299 azure_wrap.go:77] Unable to find node vm1: instance not found
--- PASS: TestGetStandardVMPowerStatusByNodeName (0.00s)
=== RUN   TestGetStandardVMProvisioningStateByNodeName
W0904 12:08:39.491109   22299 azure_wrap.go:77] Unable to find node vm1: instance not found
... skipping 7 lines ...
E0904 12:08:39.493197   22299 azure_standard.go:768] as.GetVMSetNames - No availability sets found for nodes in the cluster, node count(1)
E0904 12:08:39.493365   22299 azure_standard.go:780] as.GetVMSetNames - Availability set (vm2) in service annotation not found
--- PASS: TestGetStandardVMSetNames (0.00s)
=== RUN   TestExtractResourceGroupByNicID
--- PASS: TestExtractResourceGroupByNicID (0.00s)
=== RUN   TestStandardEnsureHostInPool
E0904 12:08:39.495039   22299 azure_standard.go:884] error: az.EnsureHostInPool(vm2), az.VMSet.GetPrimaryInterface.Get(vm2, availabilityset-1), err=resource name was missing from identifier
W0904 12:08:39.495589   22299 azure_standard.go:889] EnsureHostInPool skips node vm3 because its primary nic nic3 is in Failed state
--- PASS: TestStandardEnsureHostInPool (0.01s)
=== RUN   TestStandardEnsureHostsInPool
--- PASS: TestStandardEnsureHostsInPool (0.00s)
=== RUN   TestServiceOwnsFrontendIP
W0904 12:08:39.503515   22299 azure_standard.go:367] serviceOwnsFrontendIP: unexpected error when finding match public IP of the service  with loadBalancerLP 1.2.3.4: findMatchedPIPByLoadBalancerIP: cannot find public IP with IP address 1.2.3.4 in resource group rg
--- PASS: TestServiceOwnsFrontendIP (0.00s)
=== RUN   TestStandardEnsureBackendPoolDeleted
--- PASS: TestStandardEnsureBackendPoolDeleted (0.00s)
=== RUN   TestStandardGetNodeNameByIPConfigurationID
--- PASS: TestStandardGetNodeNameByIPConfigurationID (0.00s)
=== RUN   TestGetAvailabilitySetByNodeName
W0904 12:08:39.508184   22299 azure_standard.go:1228] Unable to find node vm-2: instance not found
E0904 12:08:39.508399   22299 azure_standard.go:472] AvailabilitySetsClient.List failed: &{false 0 0001-01-01 00:00:00 +0000 UTC error during vmas list}
--- PASS: TestGetAvailabilitySetByNodeName (0.00s)
=== RUN   TestGetNodeCIDRMasksByProviderIDAvailabilitySet
=== RUN   TestGetNodeCIDRMasksByProviderIDAvailabilitySet/GetNodeCIDRMasksByProviderID_should_report_an_error_if_the_providerID_is_not_valid
=== RUN   TestGetNodeCIDRMasksByProviderIDAvailabilitySet/GetNodeCIDRMaksByProviderID_should_return_the_correct_mask_sizes
=== RUN   TestGetNodeCIDRMasksByProviderIDAvailabilitySet/GetNodeCIDRMaksByProviderID_should_report_cloudprovider.InstanceNotFound_if_there_is_no_matching_vmas
W0904 12:08:39.510483   22299 azure_standard.go:1228] Unable to find node vm-1: instance not found
=== RUN   TestGetNodeCIDRMasksByProviderIDAvailabilitySet/GetNodeCIDRMaksByProviderID_should_return_the_correct_mask_sizes_even_if_some_of_the_tags_are_not_specified
=== RUN   TestGetNodeCIDRMasksByProviderIDAvailabilitySet/GetNodeCIDRMaksByProviderID_should_not_fail_even_if_some_of_the_tag_is_invalid
E0904 12:08:39.511982   22299 azure_standard.go:1254] GetNodeCIDRMasksByProviderID: error when paring the value of the ipv4 mask size abc: strconv.Atoi: parsing "abc": invalid syntax
--- PASS: TestGetNodeCIDRMasksByProviderIDAvailabilitySet (0.00s)
    --- PASS: TestGetNodeCIDRMasksByProviderIDAvailabilitySet/GetNodeCIDRMasksByProviderID_should_report_an_error_if_the_providerID_is_not_valid (0.00s)
    --- PASS: TestGetNodeCIDRMasksByProviderIDAvailabilitySet/GetNodeCIDRMaksByProviderID_should_return_the_correct_mask_sizes (0.00s)
    --- PASS: TestGetNodeCIDRMasksByProviderIDAvailabilitySet/GetNodeCIDRMaksByProviderID_should_report_cloudprovider.InstanceNotFound_if_there_is_no_matching_vmas (0.00s)
    --- PASS: TestGetNodeCIDRMasksByProviderIDAvailabilitySet/GetNodeCIDRMaksByProviderID_should_return_the_correct_mask_sizes_even_if_some_of_the_tags_are_not_specified (0.00s)
    --- PASS: TestGetNodeCIDRMasksByProviderIDAvailabilitySet/GetNodeCIDRMaksByProviderID_should_not_fail_even_if_some_of_the_tag_is_invalid (0.00s)
... skipping 23 lines ...
=== RUN   TestFlipServiceInternalAnnotation
--- PASS: TestFlipServiceInternalAnnotation (0.00s)
=== RUN   TestAddPort
--- PASS: TestAddPort (0.00s)
=== RUN   TestLoadBalancerInternalServiceModeSelection
E0904 12:08:39.582422   22299 azure_loadbalancer.go:917] selectLoadBalancer: cluster(testCluster) service(default/service-2) isInternal(true) -  all available load balancers have exceeded maximum rule limit 1, vmSetNames ([as])
E0904 12:08:39.582486   22299 azure_loadbalancer.go:1548] reconcileLoadBalancer: failed to get load balancer for service "default/service-2", error: selectLoadBalancer: cluster(testCluster) service(default/service-2) isInternal(true) -  all available load balancers have exceeded maximum rule limit 1, vmSetNames ([as])
E0904 12:08:39.582516   22299 azure_loadbalancer.go:94] reconcileLoadBalancer(default/service-2) failed: selectLoadBalancer: cluster(testCluster) service(default/service-2) isInternal(true) -  all available load balancers have exceeded maximum rule limit 1, vmSetNames ([as])
W0904 12:08:39.605628   22299 azure_loadbalancer.go:1446] isFrontendIPConfigUnsafeToDelete: frontend IP configuration with ID fip on LB testCluster-internal cannot be deleted because it is being referenced by load balancing rules of other services
W0904 12:08:39.606214   22299 azure_loadbalancer.go:1446] isFrontendIPConfigUnsafeToDelete: frontend IP configuration with ID fip on LB as-3-internal cannot be deleted because it is being referenced by load balancing rules of other services
W0904 12:08:39.606854   22299 azure_loadbalancer.go:1446] isFrontendIPConfigUnsafeToDelete: frontend IP configuration with ID fip on LB as-2-internal cannot be deleted because it is being referenced by load balancing rules of other services
W0904 12:08:39.607450   22299 azure_loadbalancer.go:1446] isFrontendIPConfigUnsafeToDelete: frontend IP configuration with ID fip on LB as-1-internal cannot be deleted because it is being referenced by load balancing rules of other services
W0904 12:08:39.607963   22299 azure_loadbalancer.go:1446] isFrontendIPConfigUnsafeToDelete: frontend IP configuration with ID fip on LB testCluster-internal cannot be deleted because it is being referenced by load balancing rules of other services
--- PASS: TestLoadBalancerInternalServiceModeSelection (0.09s)
=== RUN   TestLoadBalancerExternalServiceModeSelection
E0904 12:08:39.720512   22299 azure_loadbalancer.go:917] selectLoadBalancer: cluster(testCluster) service(default/service-2) isInternal(false) -  all available load balancers have exceeded maximum rule limit 1, vmSetNames ([as])
E0904 12:08:39.720584   22299 azure_loadbalancer.go:1548] reconcileLoadBalancer: failed to get load balancer for service "default/service-2", error: selectLoadBalancer: cluster(testCluster) service(default/service-2) isInternal(false) -  all available load balancers have exceeded maximum rule limit 1, vmSetNames ([as])
E0904 12:08:39.720623   22299 azure_loadbalancer.go:94] reconcileLoadBalancer(default/service-2) failed: selectLoadBalancer: cluster(testCluster) service(default/service-2) isInternal(false) -  all available load balancers have exceeded maximum rule limit 1, vmSetNames ([as])
--- PASS: TestLoadBalancerExternalServiceModeSelection (0.16s)
=== RUN   TestReconcileLoadBalancerAddServiceOnInternalSubnet
--- PASS: TestReconcileLoadBalancerAddServiceOnInternalSubnet (0.00s)
=== RUN   TestReconcileSecurityGroupFromAnyDestinationAddressPrefixToLoadBalancerIP
--- PASS: TestReconcileSecurityGroupFromAnyDestinationAddressPrefixToLoadBalancerIP (0.00s)
=== RUN   TestReconcileSecurityGroupDynamicLoadBalancerIP
... skipping 28 lines ...
--- PASS: TestReconcileSecurityGroupRemoveService (0.00s)
=== RUN   TestReconcileSecurityGroupRemoveServiceRemovesPort
--- PASS: TestReconcileSecurityGroupRemoveServiceRemovesPort (0.00s)
=== RUN   TestReconcileSecurityWithSourceRanges
--- PASS: TestReconcileSecurityWithSourceRanges (0.00s)
=== RUN   TestReconcileSecurityGroupEtagMismatch
W0904 12:08:39.807167   22299 azure_backoff.go:164] CreateOrUpdateSecurityGroup(nsg) failed: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 412, RawError: PreconditionFailedEtagMismatch, NSG request: {"properties":{"securityRules":[{"name":"aservice1-TCP-80-Internet","properties":{"access":"Allow","destinationAddressPrefix":"1.2.3.4","destinationPortRange":"80","direction":"Inbound","priority":500,"protocol":"Tcp","sourceAddressPrefix":"Internet","sourcePortRange":"*"}}]}}
--- PASS: TestReconcileSecurityGroupEtagMismatch (0.00s)
=== RUN   TestReconcilePublicIPWithNewService
--- PASS: TestReconcilePublicIPWithNewService (0.00s)
=== RUN   TestReconcilePublicIPRemoveService
--- PASS: TestReconcilePublicIPRemoveService (0.00s)
=== RUN   TestReconcilePublicIPWithInternalService
... skipping 105 lines ...
=== RUN   TestVMSSVMCacheWithDeletingNodes
W0904 12:08:42.048371   22299 azure_vmss.go:715] Unable to find node vmssee6c2000000: instance not found
W0904 12:08:42.048472   22299 azure_vmss.go:715] Unable to find node vmssee6c2000001: instance not found
W0904 12:08:42.048539   22299 azure_vmss.go:715] Unable to find node vmssee6c2000002: instance not found
--- PASS: TestVMSSVMCacheWithDeletingNodes (0.00s)
=== RUN   TestVMSSVMCacheClearedWhenRGDeleted
W0904 12:08:42.049042   22299 azure_vmss_cache.go:70] Skip caching vmss for resource group rg due to error: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 404, RawError: %!w(<nil>)
W0904 12:08:42.049123   22299 azure_vmss_cache.go:70] Skip caching vmss for resource group rg due to error: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 404, RawError: %!w(<nil>)
W0904 12:08:42.049149   22299 azure_vmss.go:715] Unable to find node vmssee6c2000000: instance not found
--- PASS: TestVMSSVMCacheClearedWhenRGDeleted (0.00s)
=== RUN   TestGetScaleSetVMInstanceID
--- PASS: TestGetScaleSetVMInstanceID (0.00s)
=== RUN   TestGetNodeIdentityByNodeName
W0904 12:08:42.050421   22299 azure_vmss.go:715] Unable to find node agente6c2000005: instance not found
... skipping 4 lines ...
--- PASS: TestGetInstanceIDByNodeName (0.00s)
=== RUN   TestGetZoneByNodeName
W0904 12:08:42.053250   22299 azure_vmss.go:715] Unable to find node agente6c2000005: instance not found
--- PASS: TestGetZoneByNodeName (0.00s)
=== RUN   TestGetIPByNodeName
W0904 12:08:42.055216   22299 azure_vmss.go:715] Unable to find node agente6c2000005: instance not found
E0904 12:08:42.055330   22299 azure_vmss.go:844] error: ss.GetPrimaryInterface(agente6c2000005), ss.getVmssVM(agente6c2000005), err=instance not found
E0904 12:08:42.055372   22299 azure_vmss.go:484] error: ss.GetIPByNodeName(agente6c2000005), GetPrimaryInterface("agente6c2000005"), err=instance not found
--- PASS: TestGetIPByNodeName (0.00s)
=== RUN   TestGetNodeNameByIPConfigurationID
E0904 12:08:42.057130   22299 azure_vmss.go:1444] Unable to find node by ipConfigurationID /subscriptions/script/resourceGroups/rg/providers/Microsoft.Compute/virtualMachineScaleSets/scaleset2/virtualMachines/3/networkInterfaces/scaleset1/ipConfigurations/ipconfig1: instance not found
E0904 12:08:42.057327   22299 azure_vmss.go:1433] Unable to find node by IPConfigurationID invalid-configuration-id: invalid ip config ID invalid-configuration-id
--- PASS: TestGetNodeNameByIPConfigurationID (0.00s)
=== RUN   TestExtractResourceGroupByVMSSNicID
--- PASS: TestExtractResourceGroupByVMSSNicID (0.00s)
=== RUN   TestGetVMSS
E0904 12:08:42.058195   22299 azure_vmss_cache.go:74] VirtualMachineScaleSetsClient.List failed: &{false 0 0001-01-01 00:00:00 +0000 UTC error during vmss list}
--- PASS: TestGetVMSS (0.00s)
=== RUN   TestGetVmssVM
W0904 12:08:42.058890   22299 azure_vmss.go:198] Unable to find node vmss-vm-000001: instance not found
--- PASS: TestGetVmssVM (0.00s)
=== RUN   TestGetPowerStatusByNodeName
--- PASS: TestGetPowerStatusByNodeName (0.00s)
=== RUN   TestGetProvisioningStateByNodeName
--- PASS: TestGetProvisioningStateByNodeName (0.00s)
=== RUN   TestGetVmssVMByInstanceID
--- PASS: TestGetVmssVMByInstanceID (0.00s)
=== RUN   TestGetInstanceTypeByNodeName
E0904 12:08:42.061170   22299 azure_backoff.go:98] VirtualMachinesClient.List(rg) failure with err=&{false 0 0001-01-01 00:00:00 +0000 UTC error}
E0904 12:08:42.061256   22299 azure_vmss.go:410] Failed to check isNodeManagedByAvailabilitySet: newAvailabilitySetNodesCache: failed to list vms in the resource group rg: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 0, RawError: error
--- PASS: TestGetInstanceTypeByNodeName (0.00s)
=== RUN   TestGetPrimaryInterfaceID
--- PASS: TestGetPrimaryInterfaceID (0.00s)
=== RUN   TestGetPrimaryInterface
E0904 12:08:42.062532   22299 azure_backoff.go:98] VirtualMachinesClient.List(rg) failure with err=&{false 0 0001-01-01 00:00:00 +0000 UTC error}
E0904 12:08:42.062678   22299 azure_vmss.go:829] Failed to check isNodeManagedByAvailabilitySet: newAvailabilitySetNodesCache: failed to list vms in the resource group rg: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 0, RawError: error
E0904 12:08:42.062919   22299 azure_vmss_cache.go:74] VirtualMachineScaleSetsClient.List failed: &{false 0 0001-01-01 00:00:00 +0000 UTC error}
E0904 12:08:42.062975   22299 azure_vmss.go:844] error: ss.GetPrimaryInterface(vmss-vm-000000), ss.getVmssVM(vmss-vm-000000), err=Retriable: false, RetryAfter: 0s, HTTPStatusCode: 0, RawError: error
E0904 12:08:42.063286   22299 azure_vmss.go:850] error: ss.GetPrimaryInterface(vmss-vm-000000), ss.getPrimaryInterfaceID(), err=failed to find a primary nic for the vm. vmname="vmss_0"
E0904 12:08:42.063630   22299 azure_vmss.go:856] error: ss.GetPrimaryInterface(vmss-vm-000000), getLastSegment(invalid/id/), err=resource name was missing from identifier
E0904 12:08:42.064295   22299 azure_vmss.go:870] error: ss.GetPrimaryInterface(vmss-vm-000000), ss.GetVirtualMachineScaleSetNetworkInterface.Get(rg, vmss, vmss-vm-000000), err=&{false 0 0001-01-01 00:00:00 +0000 UTC error}
--- PASS: TestGetPrimaryInterface (0.00s)
=== RUN   TestGetVMSSPublicIPAddress
--- PASS: TestGetVMSSPublicIPAddress (0.00s)
=== RUN   TestGetPrivateIPsByNodeName
E0904 12:08:42.067296   22299 azure_backoff.go:98] VirtualMachinesClient.List(rg) failure with err=&{false 0 0001-01-01 00:00:00 +0000 UTC error}
E0904 12:08:42.067397   22299 azure_vmss.go:829] Failed to check isNodeManagedByAvailabilitySet: newAvailabilitySetNodesCache: failed to list vms in the resource group rg: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 0, RawError: error
E0904 12:08:42.067421   22299 azure_vmss.go:547] error: ss.GetIPByNodeName(vmss-vm-000000), GetPrimaryInterface("vmss-vm-000000"), err=newAvailabilitySetNodesCache: failed to list vms in the resource group rg: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 0, RawError: error
--- PASS: TestGetPrivateIPsByNodeName (0.00s)
=== RUN   TestGetVmssMachineID
--- PASS: TestGetVmssMachineID (0.00s)
=== RUN   TestExtractScaleSetNameByProviderID
--- PASS: TestExtractScaleSetNameByProviderID (0.00s)
=== RUN   TestExtractResourceGroupByProviderID
--- PASS: TestExtractResourceGroupByProviderID (0.00s)
=== RUN   TestListScaleSets
E0904 12:08:42.068588   22299 azure_vmss.go:637] VirtualMachineScaleSetsClient.List failed: &{false 0 0001-01-01 00:00:00 +0000 UTC error}
--- PASS: TestListScaleSets (0.00s)
=== RUN   TestListScaleSetVMs
E0904 12:08:42.068892   22299 azure_vmss.go:728] VirtualMachineScaleSetVMsClient.List(rg, vmss) failed: &{false 0 0001-01-01 00:00:00 +0000 UTC error}
--- PASS: TestListScaleSetVMs (0.00s)
=== RUN   TestGetAgentPoolScaleSets
--- PASS: TestGetAgentPoolScaleSets (0.00s)
=== RUN   TestGetVMSetNames
W0904 12:08:42.069890   22299 azure_loadbalancer.go:3397] single standard load balancer doesn't work with annotation "service.beta.kubernetes.io/azure-load-balancer-mode", would ignore it
W0904 12:08:42.070164   22299 azure_vmss_cache.go:215] skip caching vmssVM vmss-vm-000003 since its network profile hasn't initialized yet (probably still under creating)
W0904 12:08:42.070404   22299 azure_vmss_cache.go:215] skip caching vmssVM vmss-vm-000003 since its network profile hasn't initialized yet (probably still under creating)
E0904 12:08:42.070444   22299 azure_vmss.go:806] ss.GetVMSetNames - scale set (vmss-1) in service annotation not found
W0904 12:08:42.070729   22299 azure_vmss_cache.go:215] skip caching vmssVM vmss-vm-000003 since its network profile hasn't initialized yet (probably still under creating)
W0904 12:08:42.070806   22299 azure_vmss_cache.go:215] skip caching vmssVM vmss-vm-000003 since its network profile hasn't initialized yet (probably still under creating)
W0904 12:08:42.070837   22299 azure_vmss.go:198] Unable to find node vmss-vm-000003: instance not found
E0904 12:08:42.070855   22299 azure_vmss.go:788] ss.GetVMSetNames - getAgentPoolScaleSets failed err=(instance not found)
W0904 12:08:42.071078   22299 azure_vmss_cache.go:215] skip caching vmssVM vmss-vm-000003 since its network profile hasn't initialized yet (probably still under creating)
--- PASS: TestGetVMSetNames (0.00s)
=== RUN   TestGetPrimaryNetworkInterfaceConfigurationForScaleSet
--- PASS: TestGetPrimaryNetworkInterfaceConfigurationForScaleSet (0.00s)
=== RUN   TestGetPrimaryIPConfigFromVMSSNetworkConfig
--- PASS: TestGetPrimaryIPConfigFromVMSSNetworkConfig (0.00s)
... skipping 13 lines ...
W0904 12:08:42.083997   22299 azure_vmss.go:198] Unable to find node vmss-vm-000001: instance not found
I0904 12:08:42.084059   22299 azure_vmss.go:1360] ensureBackendPoolDeletedFromNode: skipping node vmss-vm-000001 because it is not found
--- PASS: TestEnsureBackendPoolDeletedFromNode (0.00s)
=== RUN   TestGetScaleSetAndResourceGroupNameByIPConfigurationID
--- PASS: TestGetScaleSetAndResourceGroupNameByIPConfigurationID (0.00s)
=== RUN   TestEnsureBackendPoolDeletedFromVMSS
E0904 12:08:42.088532   22299 azure_backoff.go:526] CreateOrUpdateVMSS: error CreateOrUpdate vmss(vmss): &{false 0 0001-01-01 00:00:00 +0000 UTC error}
E0904 12:08:42.088621   22299 azure_vmss.go:1719] ensureBackendPoolDeletedFromVMSS CreateOrUpdateVMSS(vmss) with new backendPoolID /subscriptions/sub/resourceGroups/rg/providers/Microsoft.Network/loadBalancers/lb/backendAddressPools/backendpool-0, err: &{false 0 0001-01-01 00:00:00 +0000 UTC error}
--- PASS: TestEnsureBackendPoolDeletedFromVMSS (0.00s)
=== RUN   TestEnsureBackendPoolDeleted
E0904 12:08:42.089901   22299 azure_vmss.go:1433] Unable to find node by IPConfigurationID /invalid/id: invalid ip config ID /invalid/id
E0904 12:08:42.091150   22299 azure_vmss.go:1597] EnsureBackendPoolDeleted UpdateVMs for VMSS(rg, vmss) failed with error Retriable: false, RetryAfter: 0s, HTTPStatusCode: 0, RawError: error
E0904 12:08:42.092248   22299 azure_vmss.go:1444] Unable to find node by ipConfigurationID /subscriptions/sub/resourceGroups/rg/providers/Microsoft.Compute/virtualMachineScaleSets/vmss/virtualMachines/6/networkInterfaces/nic: instance not found
I0904 12:08:42.092307   22299 azure_vmss.go:1548] EnsureBackendPoolDeleted(/): skipping ip config /subscriptions/sub/resourceGroups/rg/providers/Microsoft.Compute/virtualMachineScaleSets/vmss/virtualMachines/6/networkInterfaces/nic because the corresponding vmss vm is not found
--- PASS: TestEnsureBackendPoolDeleted (0.00s)
=== RUN   TestEnsureBackendPoolDeletedConcurrently
E0904 12:08:42.093080   22299 azure_vmss.go:1655] ensureBackendPoolDeletedFromVMSS: failed to get VMSS vmss-2: instance not found
--- PASS: TestEnsureBackendPoolDeletedConcurrently (0.00s)
=== RUN   TestGetNodeCIDRMasksByProviderID
=== RUN   TestGetNodeCIDRMasksByProviderID/GetNodeCIDRMasksByProviderID_should_report_an_error_if_the_providerID_is_not_valid
=== RUN   TestGetNodeCIDRMasksByProviderID/GetNodeCIDRMaksByProviderID_should_return_the_correct_mask_sizes
=== RUN   TestGetNodeCIDRMasksByProviderID/GetNodeCIDRMaksByProviderID_should_return_the_correct_mask_sizes_even_if_some_of_the_tags_are_not_specified
=== RUN   TestGetNodeCIDRMasksByProviderID/GetNodeCIDRMaksByProviderID_should_not_fail_even_if_some_of_the_tag_is_invalid
E0904 12:08:42.096486   22299 azure_vmss.go:1634] GetNodeCIDRMasksByProviderID: error when paring the value of the ipv4 mask size abc: strconv.Atoi: parsing "abc": invalid syntax
--- PASS: TestGetNodeCIDRMasksByProviderID (0.00s)
    --- PASS: TestGetNodeCIDRMasksByProviderID/GetNodeCIDRMasksByProviderID_should_report_an_error_if_the_providerID_is_not_valid (0.00s)
    --- PASS: TestGetNodeCIDRMasksByProviderID/GetNodeCIDRMaksByProviderID_should_return_the_correct_mask_sizes (0.00s)
    --- PASS: TestGetNodeCIDRMasksByProviderID/GetNodeCIDRMaksByProviderID_should_return_the_correct_mask_sizes_even_if_some_of_the_tags_are_not_specified (0.00s)
    --- PASS: TestGetNodeCIDRMasksByProviderID/GetNodeCIDRMaksByProviderID_should_not_fail_even_if_some_of_the_tag_is_invalid (0.00s)
=== RUN   TestGetAgentPoolVMSetNamesMixedInstances
... skipping 25 lines ...
=== RUN   TestGetZoneByProviderID
--- PASS: TestGetZoneByProviderID (0.00s)
=== RUN   TestAvailabilitySetGetZoneByNodeName
--- PASS: TestAvailabilitySetGetZoneByNodeName (0.00s)
=== RUN   TestSyncRegionZonesMap
=== RUN   TestSyncRegionZonesMap/syncRegionZonesMap_should_report_an_error_if_failed_to_get_zones
W0904 12:08:42.121871   22299 azure_zones.go:51] syncRegionZonesMap: error when get zones: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 0, RawError: error, will retry after 30m0s
=== RUN   TestSyncRegionZonesMap/syncRegionZonesMap_should_not_report_an_error_if_the_given_zones_map_is_empty
W0904 12:08:42.122145   22299 azure_zones.go:55] syncRegionZonesMap: empty zone list
--- PASS: TestSyncRegionZonesMap (0.00s)
    --- PASS: TestSyncRegionZonesMap/syncRegionZonesMap_should_report_an_error_if_failed_to_get_zones (0.00s)
    --- PASS: TestSyncRegionZonesMap/syncRegionZonesMap_should_not_report_an_error_if_the_given_zones_map_is_empty (0.00s)
=== RUN   TestGetRegionZonesBackoff
=== RUN   TestGetRegionZonesBackoff/syncRegionZonesMap_should_report_an_error_if_failed_to_get_zones
E0904 12:08:42.122652   22299 azure_zones.go:93] getRegionZonesMapWrapper: failed to fetch zones information: Retriable: false, RetryAfter: 0s, HTTPStatusCode: 0, RawError: error
=== RUN   TestGetRegionZonesBackoff/syncRegionZonesMap_should_not_report_an_error_if_the_given_zones_map_is_empty
--- PASS: TestGetRegionZonesBackoff (0.00s)
    --- PASS: TestGetRegionZonesBackoff/syncRegionZonesMap_should_report_an_error_if_failed_to_get_zones (0.00s)
    --- PASS: TestGetRegionZonesBackoff/syncRegionZonesMap_should_not_report_an_error_if_the_given_zones_map_is_empty (0.00s)
PASS
ok  	sigs.k8s.io/cloud-provider-azure/pkg/provider	165.392s
... skipping 249 lines ...