[root@master-1-xp5ldNW2QAGIH csi-powerflex]# make unit-test ( cd service; go clean -cache; CGO_ENABLED=1 GO111MODULE=on go test -v -race -coverprofile=c.out ./... ) starting godog... Feature: VxFlex OS CSI interface As a consumer of the CSI interface I want to test service methods So that they are known to work goroutines start aVxFlexOSService new 4 old groutines 0 time="2023-02-01T05:45:07-05:00" level=info msg="configured 14dbbf5617523654" allSystemNames= endpoint="http://127.0.0.1" isDefault=true password="********" skipCertificateValidation=true systemID=14dbbf5617523654 user=admin time="2023-02-01T05:45:07-05:00" level=info msg="Powerflex systemID 15dbbf5617523655-system-name AllSytemNames given []string{\"15dbbf5617523655-previous-name\"}\n" time="2023-02-01T05:45:07-05:00" level=info msg="configured 15dbbf5617523655-system-name" allSystemNames=15dbbf5617523655-previous-name endpoint="http://127.0.0.2" isDefault=false password="********" skipCertificateValidation=true systemID=15dbbf5617523655-system-name user=admin time="2023-02-01T05:45:07-05:00" level=info msg="resource statistics counter: 100" GoRoutines=4 HeapAlloc=5776312 HeapReleased=778240 StackSys=425984 time="2023-02-01T05:45:07-05:00" level=info msg="driver configuration file " file=./features/driver-config/logConfig.yaml time="2023-02-01T05:45:07-05:00" level=info msg="Read CSI_LOG_FORMAT from log configuration file" format=text time="2023-02-01T05:45:07-05:00" level=info msg="Read CSI_LOG_LEVEL from log configuration file" fields.level=info time="2023-02-01T05:45:07-05:00" level=info msg="array configuration file" file=./features/array-config/config time="2023-02-01T05:45:07-05:00" level=info msg="Registering additional GRPC servers" 2023/02/01 05:45:07 Clearing volume caches goroutines end aVxFlexOSService new 12 old groutines 4 Scenario: Call probe for renaming SDC with prefix # features/service.feature:947 Given a VxFlexOS service # :1 -> *feature And I set renameSDC with renameEnabled "true" prefix "t" # :1 -> *feature goroutines before probe new 12 old groutines 12 time="2023-02-01T05:45:07-05:00" level=info msg="Probing all arrays. Number of arrays: 2" 2023/02/01 05:45:07 handler called: GET /api/login 2023/02/01 05:45:07 handler called: GET /api/version 2023/02/01 05:45:07 handler called: GET /api/types/System/instances time="2023-02-01T05:45:07-05:00" level=info msg="Found Name for system=15dbbf5617523655-system-name with ID=15dbbf5617523655" time="2023-02-01T05:45:07-05:00" level=info msg="System with name 15dbbf5617523655-system-name found id: 15dbbf5617523655" 2023/02/01 05:45:07 handler called: GET /api/types/Volume/instances time="2023-02-01T05:45:07-05:00" level=info msg="systemID: 15dbbf5617523655 has no volumes, not adding to volumePrefixToSystems map. \n" time="2023-02-01T05:45:07-05:00" level=info msg="array 15dbbf5617523655-system-name probed successfully" time="2023-02-01T05:45:07-05:00" level=info msg="System with name 15dbbf5617523655-system-name found id: 15dbbf5617523655" 2023/02/01 05:45:07 handler called: GET /api/types/Volume/instances time="2023-02-01T05:45:07-05:00" level=info msg="systemID: 15dbbf5617523655 has no volumes, not adding to volumePrefixToSystems map. \n" time="2023-02-01T05:45:07-05:00" level=info msg="array 15dbbf5617523655-system-name probed successfully" 2023/02/01 05:45:07 handler called: GET /api/login 2023/02/01 05:45:07 handler called: GET /api/version 2023/02/01 05:45:07 handler called: GET /api/types/System/instances time="2023-02-01T05:45:07-05:00" level=info msg="Found Name for system=mocksystem with ID=14dbbf5617523654" time="2023-02-01T05:45:07-05:00" level=info msg="default array is set to array ID: 14dbbf5617523654" time="2023-02-01T05:45:07-05:00" level=info msg="14dbbf5617523654 is the default array, skipping VolumePrefixToSystems map update. \n" time="2023-02-01T05:45:07-05:00" level=info msg="array 14dbbf5617523654 probed successfully" goroutines after probe new 18 old groutines 12 And I call Probe # :1 -> *feature goroutines before probe new 18 old groutines 18 time="2023-02-01T05:45:07-05:00" level=info msg="Found connected system" ID=14dbbf5617523654 2023/02/01 05:45:07 handler called: GET /api/instances/System::14dbbf5617523654/relationships/Sdc 2023/02/01 05:45:07 relationship from System id 14dbbf5617523654 to Sdc time="2023-02-01T05:45:07-05:00" level=info msg="Assigning name: t-master-1-xp5ldNW2QAGIH.domain to SDC with GUID 9E56672F-2F4B-4A42-BFF4-88B6846FBFDA on system 14dbbf5617523654" 2023/02/01 05:45:07 handler called: POST /api/instances/Sdc::d0f055a700000000/action/setSdcName 2023/02/01 05:45:07 action from Sdc id d0f055a700000000 action setSdcName SdcName: t-master-1-xp5ldNW2QAGIH.domain 2023/02/01 05:45:07 handler called: GET /api/instances/System::14dbbf5617523654/relationships/Sdc 2023/02/01 05:45:07 relationship from System id 14dbbf5617523654 to Sdc time="2023-02-01T05:45:07-05:00" level=info msg="SDC name set to: t-master-1-xp5ldNW2QAGIH.domain." goroutines after probe new 18 old groutines 18 When I call Node Probe # :1 -> *feature goroutines theErrorContains new 18 old groutines 18 Then the error contains "none" # :1 -> *feature goroutines start aVxFlexOSService new 14 old groutines 0 time="2023-02-01T05:45:07-05:00" level=info msg="configured 14dbbf5617523654" allSystemNames= endpoint="http://127.0.0.1" isDefault=true password="********" skipCertificateValidation=true systemID=14dbbf5617523654 user=admin time="2023-02-01T05:45:07-05:00" level=info msg="Powerflex systemID 15dbbf5617523655-system-name AllSytemNames given []string{\"15dbbf5617523655-previous-name\"}\n" time="2023-02-01T05:45:07-05:00" level=info msg="configured 15dbbf5617523655-system-name" allSystemNames=15dbbf5617523655-previous-name endpoint="http://127.0.0.2" isDefault=false password="********" skipCertificateValidation=true systemID=15dbbf5617523655-system-name user=admin time="2023-02-01T05:45:07-05:00" level=info msg="resource statistics counter: 100" GoRoutines=14 HeapAlloc=4502832 HeapReleased=3227648 StackSys=655360 time="2023-02-01T05:45:07-05:00" level=info msg="Registering additional GRPC servers" 2023/02/01 05:45:07 Clearing volume caches goroutines end aVxFlexOSService new 16 old groutines 14 Scenario: Call probe for renaming SDC without prefix # features/service.feature:955 Given a VxFlexOS service # :1 -> *feature And I set renameSDC with renameEnabled "true" prefix "" # :1 -> *feature goroutines before probe new 16 old groutines 16 time="2023-02-01T05:45:07-05:00" level=info msg="Probing all arrays. Number of arrays: 2" 2023/02/01 05:45:07 handler called: GET /api/login 2023/02/01 05:45:07 handler called: GET /api/version 2023/02/01 05:45:07 handler called: GET /api/types/System/instances time="2023-02-01T05:45:07-05:00" level=info msg="Found Name for system=mocksystem with ID=14dbbf5617523654" time="2023-02-01T05:45:07-05:00" level=info msg="default array is set to array ID: 14dbbf5617523654" time="2023-02-01T05:45:07-05:00" level=info msg="14dbbf5617523654 is the default array, skipping VolumePrefixToSystems map update. \n" time="2023-02-01T05:45:07-05:00" level=info msg="array 14dbbf5617523654 probed successfully" 2023/02/01 05:45:07 handler called: GET /api/login 2023/02/01 05:45:07 handler called: GET /api/version 2023/02/01 05:45:07 handler called: GET /api/types/System/instances time="2023-02-01T05:45:07-05:00" level=info msg="Found Name for system=15dbbf5617523655-system-name with ID=15dbbf5617523655" time="2023-02-01T05:45:07-05:00" level=info msg="System with name 15dbbf5617523655-system-name found id: 15dbbf5617523655" 2023/02/01 05:45:07 handler called: GET /api/types/Volume/instances time="2023-02-01T05:45:07-05:00" level=info msg="systemID: 15dbbf5617523655 has no volumes, not adding to volumePrefixToSystems map. \n" time="2023-02-01T05:45:07-05:00" level=info msg="array 15dbbf5617523655-system-name probed successfully" time="2023-02-01T05:45:07-05:00" level=info msg="System with name 15dbbf5617523655-system-name found id: 15dbbf5617523655" 2023/02/01 05:45:07 handler called: GET /api/types/Volume/instances time="2023-02-01T05:45:07-05:00" level=info msg="systemID: 15dbbf5617523655 has no volumes, not adding to volumePrefixToSystems map. \n" time="2023-02-01T05:45:07-05:00" level=info msg="array 15dbbf5617523655-system-name probed successfully" goroutines after probe new 22 old groutines 16 And I call Probe # :1 -> *feature goroutines before probe new 22 old groutines 22 2023/02/01 05:45:07 handler called: GET /api/instances/System::14dbbf5617523654/relationships/Sdc 2023/02/01 05:45:07 relationship from System id 14dbbf5617523654 to Sdc time="2023-02-01T05:45:07-05:00" level=info msg="Assigning name: master-1-xp5ldNW2QAGIH.domain to SDC with GUID 9E56672F-2F4B-4A42-BFF4-88B6846FBFDA on system 14dbbf5617523654" 2023/02/01 05:45:07 handler called: POST /api/instances/Sdc::d0f055a700000000/action/setSdcName 2023/02/01 05:45:07 action from Sdc id d0f055a700000000 action setSdcName SdcName: master-1-xp5ldNW2QAGIH.domain 2023/02/01 05:45:07 handler called: GET /api/instances/System::14dbbf5617523654/relationships/Sdc 2023/02/01 05:45:07 relationship from System id 14dbbf5617523654 to Sdc time="2023-02-01T05:45:07-05:00" level=info msg="SDC name set to: master-1-xp5ldNW2QAGIH.domain." goroutines after probe new 22 old groutines 22 When I call Node Probe # :1 -> *feature goroutines theErrorContains new 22 old groutines 22 Then the error contains "none" # :1 -> *feature goroutines start aVxFlexOSService new 18 old groutines 0 time="2023-02-01T05:45:07-05:00" level=info msg="configured 14dbbf5617523654" allSystemNames= endpoint="http://127.0.0.1" isDefault=true password="********" skipCertificateValidation=true systemID=14dbbf5617523654 user=admin time="2023-02-01T05:45:07-05:00" level=info msg="Powerflex systemID 15dbbf5617523655-system-name AllSytemNames given []string{\"15dbbf5617523655-previous-name\"}\n" time="2023-02-01T05:45:07-05:00" level=info msg="configured 15dbbf5617523655-system-name" allSystemNames=15dbbf5617523655-previous-name endpoint="http://127.0.0.2" isDefault=false password="********" skipCertificateValidation=true systemID=15dbbf5617523655-system-name user=admin time="2023-02-01T05:45:07-05:00" level=info msg="resource statistics counter: 100" GoRoutines=18 HeapAlloc=6784680 HeapReleased=2842624 StackSys=589824 time="2023-02-01T05:45:07-05:00" level=info msg="Registering additional GRPC servers" 2023/02/01 05:45:07 Clearing volume caches goroutines end aVxFlexOSService new 20 old groutines 18 Scenario: Call probe for renaming SDC, renameSdc error # features/service.feature:963 Given a VxFlexOS service # :1 -> *feature 2023/02/01 05:45:07 set induce error SetSdcNameError And I induce error "SetSdcNameError" # :1 -> *feature And I set renameSDC with renameEnabled "true" prefix "t" # :1 -> *feature goroutines before probe new 20 old groutines 20 time="2023-02-01T05:45:07-05:00" level=info msg="Probing all arrays. Number of arrays: 2" 2023/02/01 05:45:07 handler called: GET /api/login 2023/02/01 05:45:07 handler called: GET /api/version 2023/02/01 05:45:07 handler called: GET /api/types/System/instances time="2023-02-01T05:45:07-05:00" level=info msg="Found Name for system=mocksystem with ID=14dbbf5617523654" time="2023-02-01T05:45:07-05:00" level=info msg="default array is set to array ID: 14dbbf5617523654" time="2023-02-01T05:45:07-05:00" level=info msg="14dbbf5617523654 is the default array, skipping VolumePrefixToSystems map update. \n" time="2023-02-01T05:45:07-05:00" level=info msg="array 14dbbf5617523654 probed successfully" 2023/02/01 05:45:07 handler called: GET /api/login 2023/02/01 05:45:07 handler called: GET /api/version 2023/02/01 05:45:07 handler called: GET /api/types/System/instances time="2023-02-01T05:45:07-05:00" level=info msg="Found Name for system=15dbbf5617523655-system-name with ID=15dbbf5617523655" time="2023-02-01T05:45:07-05:00" level=info msg="System with name 15dbbf5617523655-system-name found id: 15dbbf5617523655" 2023/02/01 05:45:07 handler called: GET /api/types/Volume/instances time="2023-02-01T05:45:07-05:00" level=info msg="systemID: 15dbbf5617523655 has no volumes, not adding to volumePrefixToSystems map. \n" time="2023-02-01T05:45:07-05:00" level=info msg="array 15dbbf5617523655-system-name probed successfully" time="2023-02-01T05:45:07-05:00" level=info msg="System with name 15dbbf5617523655-system-name found id: 15dbbf5617523655" 2023/02/01 05:45:07 handler called: GET /api/types/Volume/instances time="2023-02-01T05:45:07-05:00" level=info msg="systemID: 15dbbf5617523655 has no volumes, not adding to volumePrefixToSystems map. \n" time="2023-02-01T05:45:07-05:00" level=info msg="array 15dbbf5617523655-system-name probed successfully" goroutines after probe new 26 old groutines 20 And I call Probe # :1 -> *feature goroutines before probe new 26 old groutines 26 2023/02/01 05:45:07 handler called: GET /api/instances/System::14dbbf5617523654/relationships/Sdc 2023/02/01 05:45:07 relationship from System id 14dbbf5617523654 to Sdc time="2023-02-01T05:45:07-05:00" level=info msg="Assigning name: t-master-1-xp5ldNW2QAGIH.domain to SDC with GUID 9E56672F-2F4B-4A42-BFF4-88B6846FBFDA on system 14dbbf5617523654" 2023/02/01 05:45:07 handler called: POST /api/instances/Sdc::d0f055a700000000/action/setSdcName 2023/02/01 05:45:07 action from Sdc id d0f055a700000000 action setSdcName time="2023-02-01T05:45:07-05:00" level=info msg="error in nodeProbe: rpc error: code = FailedPrecondition desc = Failed to rename SDC: induced error" goroutines after probe new 26 old groutines 26 When I call Node Probe # :1 -> *feature goroutines theErrorContains new 26 old groutines 26 Then the error contains "Failed to rename SDC" # :1 -> *feature goroutines start aVxFlexOSService new 22 old groutines 0 time="2023-02-01T05:45:07-05:00" level=info msg="configured 14dbbf5617523654" allSystemNames= endpoint="http://127.0.0.1" isDefault=true password="********" skipCertificateValidation=true systemID=14dbbf5617523654 user=admin time="2023-02-01T05:45:07-05:00" level=info msg="Powerflex systemID 15dbbf5617523655-system-name AllSytemNames given []string{\"15dbbf5617523655-previous-name\"}\n" time="2023-02-01T05:45:07-05:00" level=info msg="configured 15dbbf5617523655-system-name" allSystemNames=15dbbf5617523655-previous-name endpoint="http://127.0.0.2" isDefault=false password="********" skipCertificateValidation=true systemID=15dbbf5617523655-system-name user=admin time="2023-02-01T05:45:07-05:00" level=info msg="resource statistics counter: 100" GoRoutines=22 HeapAlloc=4341776 HeapReleased=2031616 StackSys=655360 time="2023-02-01T05:45:07-05:00" level=info msg="Registering additional GRPC servers" 2023/02/01 05:45:07 Clearing volume caches goroutines end aVxFlexOSService new 24 old groutines 22 Scenario: Call probe for renaming SDC, sdc error # features/service.feature:972 Given a VxFlexOS service # :1 -> *feature 2023/02/01 05:45:07 set induce error GetSdcInstancesError And I induce error "GetSdcInstancesError" # :1 -> *feature And I set renameSDC with renameEnabled "true" prefix "t" # :1 -> *feature goroutines before probe new 24 old groutines 24 time="2023-02-01T05:45:07-05:00" level=info msg="Probing all arrays. Number of arrays: 2" 2023/02/01 05:45:07 handler called: GET /api/login 2023/02/01 05:45:07 handler called: GET /api/version 2023/02/01 05:45:07 handler called: GET /api/types/System/instances time="2023-02-01T05:45:07-05:00" level=info msg="Found Name for system=mocksystem with ID=14dbbf5617523654" time="2023-02-01T05:45:07-05:00" level=info msg="default array is set to array ID: 14dbbf5617523654" time="2023-02-01T05:45:07-05:00" level=info msg="14dbbf5617523654 is the default array, skipping VolumePrefixToSystems map update. \n" time="2023-02-01T05:45:07-05:00" level=info msg="array 14dbbf5617523654 probed successfully" 2023/02/01 05:45:07 handler called: GET /api/login 2023/02/01 05:45:07 handler called: GET /api/version 2023/02/01 05:45:07 handler called: GET /api/types/System/instances time="2023-02-01T05:45:07-05:00" level=info msg="Found Name for system=15dbbf5617523655-system-name with ID=15dbbf5617523655" time="2023-02-01T05:45:07-05:00" level=info msg="System with name 15dbbf5617523655-system-name found id: 15dbbf5617523655" 2023/02/01 05:45:07 handler called: GET /api/types/Volume/instances time="2023-02-01T05:45:07-05:00" level=info msg="systemID: 15dbbf5617523655 has no volumes, not adding to volumePrefixToSystems map. \n" time="2023-02-01T05:45:07-05:00" level=info msg="array 15dbbf5617523655-system-name probed successfully" time="2023-02-01T05:45:07-05:00" level=info msg="System with name 15dbbf5617523655-system-name found id: 15dbbf5617523655" 2023/02/01 05:45:07 handler called: GET /api/types/Volume/instances time="2023-02-01T05:45:07-05:00" level=info msg="systemID: 15dbbf5617523655 has no volumes, not adding to volumePrefixToSystems map. \n" time="2023-02-01T05:45:07-05:00" level=info msg="array 15dbbf5617523655-system-name probed successfully" goroutines after probe new 30 old groutines 24 And I call Probe # :1 -> *feature goroutines before probe new 30 old groutines 30 2023/02/01 05:45:07 handler called: GET /api/instances/System::14dbbf5617523654/relationships/Sdc 2023/02/01 05:45:07 relationship from System id 14dbbf5617523654 to Sdc time="2023-02-01T05:45:07-05:00" level=info msg="error in nodeProbe: rpc error: code = FailedPrecondition desc = induced error" goroutines after probe new 28 old groutines 30 When I call Node Probe # :1 -> *feature goroutines theErrorContains new 28 old groutines 28 Then the error contains "induced error" # :1 -> *feature 4 scenarios (4 passed) 22 steps (22 passed) 230.558748ms