pull-azuredisk-csi-driver-sanity #1179092917625556994 Results

Error lines from build-log.txt

Raw build-log.txt
... skipping 714 lines ...
I1001 18:04:24.268] ListSnapshots [Controller Server]
I1001 18:04:24.268] /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/tests.go:44
I1001 18:04:24.268]   should return next token when a limited number of entries are requested
I1001 18:04:24.269]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:1331
I1001 18:04:24.269] ------------------------------
I1001 18:04:24.269] DeleteSnapshot [Controller Server] 
I1001 18:04:24.269]   should fail when no snapshot id is provided
I1001 18:04:24.270]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:1439
I1001 18:04:24.270] STEP: reusing connection to CSI driver at unix:///tmp/csi.sock
I1001 18:04:24.270] STEP: creating mount and staging directories
I1001 18:04:24.270] I1001 18:04:24.267129    8886 utils.go:112] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1001 18:04:24.270] I1001 18:04:24.267155    8886 utils.go:113] GRPC request: 
I1001 18:04:24.270] I1001 18:04:24.267162    8886 controllerserver.go:415] Using default ControllerGetCapabilities
I1001 18:04:24.271] I1001 18:04:24.267167    8886 utils.go:119] GRPC response: capabilities:<rpc:<type:CREATE_DELETE_VOLUME > > capabilities:<rpc:<type:PUBLISH_UNPUBLISH_VOLUME > > capabilities:<rpc:<type:CREATE_DELETE_SNAPSHOT > > capabilities:<rpc:<type:LIST_SNAPSHOTS > > 
I1001 18:04:24.271] I1001 18:04:24.267783    8886 utils.go:112] GRPC call: /csi.v1.Controller/DeleteSnapshot
I1001 18:04:24.271] I1001 18:04:24.267820    8886 utils.go:113] GRPC request: 
I1001 18:04:24.271] I1001 18:04:24.267831    8886 controllerserver.go:491] DeleteSnapshot called with request { map[] {} [] 0}
I1001 18:04:24.271] E1001 18:04:24.267853    8886 utils.go:117] GRPC error: rpc error: code = InvalidArgument desc = Snapshot ID must be provided
I1001 18:04:24.272] •
I1001 18:04:24.272] ------------------------------
I1001 18:04:24.272] DeleteSnapshot [Controller Server] 
I1001 18:04:24.272]   should succeed when an invalid snapshot id is used
I1001 18:04:24.272]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:1455
I1001 18:04:24.272] STEP: reusing connection to CSI driver at unix:///tmp/csi.sock
... skipping 109 lines ...
I1001 18:04:47.102] 
I1001 18:04:47.103]     ListVolumes not supported
I1001 18:04:47.103] 
I1001 18:04:47.103]     /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:157
I1001 18:04:47.103] ------------------------------
I1001 18:04:47.103] Controller Service CreateVolume 
I1001 18:04:47.103]   should fail when no name is provided
I1001 18:04:47.104]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:186
I1001 18:04:47.104] STEP: reusing connection to CSI driver at unix:///tmp/csi.sock
I1001 18:04:47.104] STEP: creating mount and staging directories
I1001 18:04:47.104] I1001 18:04:47.093642    8886 utils.go:112] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1001 18:04:47.104] I1001 18:04:47.093669    8886 utils.go:113] GRPC request: 
I1001 18:04:47.104] I1001 18:04:47.093675    8886 controllerserver.go:415] Using default ControllerGetCapabilities
I1001 18:04:47.105] I1001 18:04:47.093679    8886 utils.go:119] GRPC response: capabilities:<rpc:<type:CREATE_DELETE_VOLUME > > capabilities:<rpc:<type:PUBLISH_UNPUBLISH_VOLUME > > capabilities:<rpc:<type:CREATE_DELETE_SNAPSHOT > > capabilities:<rpc:<type:LIST_SNAPSHOTS > > 
I1001 18:04:47.105] I1001 18:04:47.094206    8886 utils.go:112] GRPC call: /csi.v1.Controller/CreateVolume
I1001 18:04:47.105] I1001 18:04:47.094243    8886 utils.go:113] GRPC request: 
I1001 18:04:47.105] E1001 18:04:47.094254    8886 utils.go:117] GRPC error: rpc error: code = InvalidArgument desc = CreateVolume Name must be provided
I1001 18:04:47.105] •
I1001 18:04:47.105] ------------------------------
I1001 18:04:47.106] Controller Service CreateVolume 
I1001 18:04:47.106]   should fail when no volume capabilities are provided
I1001 18:04:47.106]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:202
I1001 18:04:47.106] STEP: reusing connection to CSI driver at unix:///tmp/csi.sock
I1001 18:04:47.106] STEP: creating mount and staging directories
I1001 18:04:47.106] I1001 18:04:47.094702    8886 utils.go:112] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1001 18:04:47.106] I1001 18:04:47.094730    8886 utils.go:113] GRPC request: 
I1001 18:04:47.107] I1001 18:04:47.094738    8886 controllerserver.go:415] Using default ControllerGetCapabilities
I1001 18:04:47.107] I1001 18:04:47.094744    8886 utils.go:119] GRPC response: capabilities:<rpc:<type:CREATE_DELETE_VOLUME > > capabilities:<rpc:<type:PUBLISH_UNPUBLISH_VOLUME > > capabilities:<rpc:<type:CREATE_DELETE_SNAPSHOT > > capabilities:<rpc:<type:LIST_SNAPSHOTS > > 
I1001 18:04:47.107] I1001 18:04:47.095484    8886 utils.go:112] GRPC call: /csi.v1.Controller/CreateVolume
I1001 18:04:47.107] I1001 18:04:47.095511    8886 utils.go:113] GRPC request: name:"sanity-controller-create-no-volume-capabilities-7632817E-817F5FAA" 
I1001 18:04:47.108] E1001 18:04:47.095520    8886 utils.go:117] GRPC error: rpc error: code = InvalidArgument desc = CreateVolume Volume capabilities must be provided
I1001 18:04:47.108] •
I1001 18:04:47.108] ------------------------------
I1001 18:04:47.108] Controller Service CreateVolume 
I1001 18:04:47.108]   should return appropriate values SingleNodeWriter NoCapacity Type:Mount
I1001 18:04:47.108]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:220
I1001 18:04:47.109] STEP: reusing connection to CSI driver at unix:///tmp/csi.sock
... skipping 57 lines ...
I1001 18:04:59.447]   CreateVolume
I1001 18:04:59.447]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:179
I1001 18:04:59.448]     should return appropriate values SingleNodeWriter WithCapacity 1Gi Type:Mount
I1001 18:04:59.448]     /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:262
I1001 18:04:59.448] ------------------------------
I1001 18:04:59.448] Controller Service CreateVolume 
I1001 18:04:59.448]   should not fail when requesting to create a volume with already existing name and same capacity.
I1001 18:04:59.449]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:311
I1001 18:04:59.449] STEP: reusing connection to CSI driver at unix:///tmp/csi.sock
I1001 18:04:59.449] STEP: creating mount and staging directories
I1001 18:04:59.449] I1001 18:04:59.446194    8886 utils.go:112] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1001 18:04:59.449] I1001 18:04:59.446235    8886 utils.go:113] GRPC request: 
I1001 18:04:59.450] I1001 18:04:59.446245    8886 controllerserver.go:415] Using default ControllerGetCapabilities
... skipping 23 lines ...
I1001 18:05:06.134] 
I1001 18:05:06.135] • [SLOW TEST:6.688 seconds]
I1001 18:05:06.135] Controller Service
I1001 18:05:06.135] /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/tests.go:44
I1001 18:05:06.135]   CreateVolume
I1001 18:05:06.135]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:179
I1001 18:05:06.135]     should not fail when requesting to create a volume with already existing name and same capacity.
I1001 18:05:06.135]     /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:311
I1001 18:05:06.136] ------------------------------
I1001 18:05:06.136] Controller Service CreateVolume 
I1001 18:05:06.136]   should fail when requesting to create a volume with already existing name and different capacity.
I1001 18:05:06.136]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:385
I1001 18:05:06.136] STEP: reusing connection to CSI driver at unix:///tmp/csi.sock
I1001 18:05:06.136] STEP: creating mount and staging directories
I1001 18:05:06.136] I1001 18:05:06.134358    8886 utils.go:112] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1001 18:05:06.137] I1001 18:05:06.134413    8886 utils.go:113] GRPC request: 
I1001 18:05:06.137] I1001 18:05:06.134437    8886 controllerserver.go:415] Using default ControllerGetCapabilities
... skipping 5 lines ...
I1001 18:05:06.217] I1001 18:05:06.216628    8886 azuredisk.go:244] azureDisk - creating new managed Name:sanity-controller-create-twice-different-7632817E-817F5FAA StorageAccountType:Standard_LRS Size:10
I1001 18:05:06.979] I1001 18:05:06.979167    8886 azuredisk.go:348] azureDisk - created new MD Name:sanity-controller-create-twice-different-7632817E-817F5FAA StorageAccountType:Standard_LRS Size:10
I1001 18:05:06.980] I1001 18:05:06.979207    8886 controllerserver.go:222] create azure disk(sanity-controller-create-twice-different-7632817E-817F5FAA) account type(Standard_LRS) rg(azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc) location() size(10) successfully
I1001 18:05:06.980] I1001 18:05:06.979217    8886 utils.go:119] GRPC response: volume:<capacity_bytes:10737418240 volume_id:"/subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc/providers/Microsoft.Compute/disks/sanity-controller-create-twice-different-7632817E-817F5FAA" accessible_topology:<segments:<key:"topology.disk.csi.azure.com/zone" value:"" > > > 
I1001 18:05:06.980] I1001 18:05:06.979990    8886 utils.go:112] GRPC call: /csi.v1.Controller/CreateVolume
I1001 18:05:06.981] I1001 18:05:06.980025    8886 utils.go:113] GRPC request: name:"sanity-controller-create-twice-different-7632817E-817F5FAA" capacity_range:<required_bytes:21474836480 limit_bytes:21474836480 > volume_capabilities:<mount:<> access_mode:<mode:SINGLE_NODE_WRITER > > 
I1001 18:05:07.082] E1001 18:05:07.081964    8886 utils.go:117] GRPC error: rpc error: code = AlreadyExists desc = the request volume already exists, but its capacity(10) is different from (20)
I1001 18:05:07.082] STEP: cleaning up deleting the volume
I1001 18:05:07.082] I1001 18:05:07.082565    8886 utils.go:112] GRPC call: /csi.v1.Controller/DeleteVolume
I1001 18:05:07.083] I1001 18:05:07.082597    8886 utils.go:113] GRPC request: volume_id:"/subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc/providers/Microsoft.Compute/disks/sanity-controller-create-twice-different-7632817E-817F5FAA" 
I1001 18:05:07.083] I1001 18:05:07.082622    8886 controllerserver.go:277] deleting azure disk(/subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc/providers/Microsoft.Compute/disks/sanity-controller-create-twice-different-7632817E-817F5FAA)
I1001 18:05:12.563] I1001 18:05:12.562500    8886 azure_managedDiskController.go:195] azureDisk - deleted a managed disk: /subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc/providers/Microsoft.Compute/disks/sanity-controller-create-twice-different-7632817E-817F5FAA
I1001 18:05:12.563] I1001 18:05:12.562555    8886 controllerserver.go:287] delete azure disk(/subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc/providers/Microsoft.Compute/disks/sanity-controller-create-twice-different-7632817E-817F5FAA) successfully
I1001 18:05:12.563] I1001 18:05:12.562564    8886 utils.go:119] GRPC response: 
I1001 18:05:12.564] 
I1001 18:05:12.564] • [SLOW TEST:6.430 seconds]
I1001 18:05:12.564] Controller Service
I1001 18:05:12.564] /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/tests.go:44
I1001 18:05:12.564]   CreateVolume
I1001 18:05:12.565]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:179
I1001 18:05:12.565]     should fail when requesting to create a volume with already existing name and different capacity.
I1001 18:05:12.565]     /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:385
I1001 18:05:12.566] ------------------------------
I1001 18:05:12.566] Controller Service CreateVolume 
I1001 18:05:12.566]   should not fail when creating volume with maximum-length name
I1001 18:05:12.566]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:460
I1001 18:05:12.567] STEP: reusing connection to CSI driver at unix:///tmp/csi.sock
I1001 18:05:12.567] STEP: creating mount and staging directories
I1001 18:05:12.567] I1001 18:05:12.564678    8886 utils.go:112] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1001 18:05:12.567] I1001 18:05:12.564699    8886 utils.go:113] GRPC request: 
I1001 18:05:12.567] I1001 18:05:12.564708    8886 controllerserver.go:415] Using default ControllerGetCapabilities
... skipping 17 lines ...
I1001 18:05:18.817] 
I1001 18:05:18.817] • [SLOW TEST:6.252 seconds]
I1001 18:05:18.817] Controller Service
I1001 18:05:18.818] /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/tests.go:44
I1001 18:05:18.818]   CreateVolume
I1001 18:05:18.818]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:179
I1001 18:05:18.819]     should not fail when creating volume with maximum-length name
I1001 18:05:18.819]     /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:460
I1001 18:05:18.819] ------------------------------
I1001 18:05:18.819] Controller Service DeleteVolume 
I1001 18:05:18.819]   should fail when no volume id is provided
I1001 18:05:18.820]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:519
I1001 18:05:18.820] STEP: reusing connection to CSI driver at unix:///tmp/csi.sock
I1001 18:05:18.820] STEP: creating mount and staging directories
I1001 18:05:18.820] I1001 18:05:18.816785    8886 utils.go:112] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1001 18:05:18.821] I1001 18:05:18.816817    8886 utils.go:113] GRPC request: 
I1001 18:05:18.821] I1001 18:05:18.816828    8886 controllerserver.go:415] Using default ControllerGetCapabilities
I1001 18:05:18.821] I1001 18:05:18.816834    8886 utils.go:119] GRPC response: capabilities:<rpc:<type:CREATE_DELETE_VOLUME > > capabilities:<rpc:<type:PUBLISH_UNPUBLISH_VOLUME > > capabilities:<rpc:<type:CREATE_DELETE_SNAPSHOT > > capabilities:<rpc:<type:LIST_SNAPSHOTS > > 
I1001 18:05:18.822] I1001 18:05:18.817396    8886 utils.go:112] GRPC call: /csi.v1.Controller/DeleteVolume
I1001 18:05:18.822] I1001 18:05:18.817431    8886 utils.go:113] GRPC request: 
I1001 18:05:18.822] E1001 18:05:18.817440    8886 utils.go:117] GRPC error: rpc error: code = InvalidArgument desc = Volume ID missing in request
I1001 18:05:18.822] •
I1001 18:05:18.822] ------------------------------
I1001 18:05:18.823] Controller Service DeleteVolume 
I1001 18:05:18.823]   should succeed when an invalid volume id is used
I1001 18:05:18.823]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:534
I1001 18:05:18.823] STEP: reusing connection to CSI driver at unix:///tmp/csi.sock
I1001 18:05:18.824] STEP: creating mount and staging directories
I1001 18:05:18.824] I1001 18:05:18.818117    8886 utils.go:112] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1001 18:05:18.824] I1001 18:05:18.818168    8886 utils.go:113] GRPC request: 
I1001 18:05:18.824] I1001 18:05:18.818179    8886 controllerserver.go:415] Using default ControllerGetCapabilities
I1001 18:05:18.825] I1001 18:05:18.818185    8886 utils.go:119] GRPC response: capabilities:<rpc:<type:CREATE_DELETE_VOLUME > > capabilities:<rpc:<type:PUBLISH_UNPUBLISH_VOLUME > > capabilities:<rpc:<type:CREATE_DELETE_SNAPSHOT > > capabilities:<rpc:<type:LIST_SNAPSHOTS > > 
I1001 18:05:18.825] I1001 18:05:18.818653    8886 utils.go:112] GRPC call: /csi.v1.Controller/DeleteVolume
I1001 18:05:18.825] I1001 18:05:18.818683    8886 utils.go:113] GRPC request: volume_id:"reallyfakevolumeid" 
I1001 18:05:18.825] E1001 18:05:18.818698    8886 controllerserver.go:273] validateDiskURI(reallyfakevolumeid) in DeleteVolume failed with error: Inavlid DiskURI: reallyfakevolumeid, correct format: [/subscriptions/{sub-id}/resourcegroups/{group-name}/providers/microsoft.compute/disks/{disk-id}]
I1001 18:05:18.826] I1001 18:05:18.818705    8886 utils.go:119] GRPC response: 
I1001 18:05:18.826] •
I1001 18:05:18.826] ------------------------------
I1001 18:05:18.826] Controller Service DeleteVolume 
I1001 18:05:18.827]   should return appropriate values (no optional values added)
I1001 18:05:18.827]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:546
... skipping 18 lines ...
I1001 18:05:19.941] I1001 18:05:19.941047    8886 azure_managedDiskController.go:195] azureDisk - deleted a managed disk: /subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc/providers/Microsoft.Compute/disks/sanity-controller-create-appropriate-7632817E-817F5FAA
I1001 18:05:19.941] I1001 18:05:19.941079    8886 controllerserver.go:287] delete azure disk(/subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc/providers/Microsoft.Compute/disks/sanity-controller-create-appropriate-7632817E-817F5FAA) successfully
I1001 18:05:19.942] I1001 18:05:19.941087    8886 utils.go:119] GRPC response: 
I1001 18:05:19.942] •
I1001 18:05:19.942] ------------------------------
I1001 18:05:19.942] Controller Service ValidateVolumeCapabilities 
I1001 18:05:19.943]   should fail when no volume id is provided
I1001 18:05:19.943]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:592
I1001 18:05:19.943] STEP: reusing connection to CSI driver at unix:///tmp/csi.sock
I1001 18:05:19.943] STEP: creating mount and staging directories
I1001 18:05:19.944] I1001 18:05:19.941885    8886 utils.go:112] GRPC call: /csi.v1.Controller/ValidateVolumeCapabilities
I1001 18:05:19.944] I1001 18:05:19.941924    8886 utils.go:113] GRPC request: 
I1001 18:05:19.944] E1001 18:05:19.941936    8886 utils.go:117] GRPC error: rpc error: code = InvalidArgument desc = Volume ID missing in request
I1001 18:05:19.944] •
I1001 18:05:19.944] ------------------------------
I1001 18:05:19.944] Controller Service ValidateVolumeCapabilities 
I1001 18:05:19.945]   should fail when no volume capabilities are provided
I1001 18:05:19.945]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:604
I1001 18:05:19.945] STEP: reusing connection to CSI driver at unix:///tmp/csi.sock
I1001 18:05:19.945] STEP: creating mount and staging directories
I1001 18:05:19.945] I1001 18:05:19.942528    8886 utils.go:112] GRPC call: /csi.v1.Controller/ValidateVolumeCapabilities
I1001 18:05:19.946] I1001 18:05:19.942562    8886 utils.go:113] GRPC request: volume_id:"id" 
I1001 18:05:19.946] E1001 18:05:19.942572    8886 utils.go:117] GRPC error: rpc error: code = InvalidArgument desc = Volume capabilities missing in request
I1001 18:05:19.946] •
I1001 18:05:19.946] ------------------------------
I1001 18:05:19.946] Controller Service ValidateVolumeCapabilities 
I1001 18:05:19.946]   should return appropriate values (no optional values added)
I1001 18:05:19.947]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:618
I1001 18:05:19.947] STEP: reusing connection to CSI driver at unix:///tmp/csi.sock
... skipping 24 lines ...
I1001 18:05:26.290]   ValidateVolumeCapabilities
I1001 18:05:26.290]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:591
I1001 18:05:26.290]     should return appropriate values (no optional values added)
I1001 18:05:26.290]     /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:618
I1001 18:05:26.291] ------------------------------
I1001 18:05:26.291] Controller Service ValidateVolumeCapabilities 
I1001 18:05:26.291]   should fail when the requested volume does not exist
I1001 18:05:26.291]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:687
I1001 18:05:26.292] STEP: reusing connection to CSI driver at unix:///tmp/csi.sock
I1001 18:05:26.292] STEP: creating mount and staging directories
I1001 18:05:26.292] I1001 18:05:26.288458    8886 utils.go:112] GRPC call: /csi.v1.Controller/ValidateVolumeCapabilities
I1001 18:05:26.292] I1001 18:05:26.288485    8886 utils.go:113] GRPC request: volume_id:"some-vol-id" volume_capabilities:<mount:<> access_mode:<mode:SINGLE_NODE_WRITER > > 
I1001 18:05:26.293] E1001 18:05:26.288504    8886 utils.go:117] GRPC error: rpc error: code = NotFound desc = Volume not found, failed with error: could not get disk name from some-vol-id, correct format: .*/subscriptions/(?:.*)/resourceGroups/(?:.*)/providers/Microsoft.Compute/disks/(.+)
I1001 18:05:26.293] •
I1001 18:05:26.293] ------------------------------
I1001 18:05:26.294] Controller Service ControllerPublishVolume 
I1001 18:05:26.294]   should fail when no volume id is provided
I1001 18:05:26.294]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:720
I1001 18:05:26.294] STEP: reusing connection to CSI driver at unix:///tmp/csi.sock
I1001 18:05:26.294] STEP: creating mount and staging directories
I1001 18:05:26.295] I1001 18:05:26.289188    8886 utils.go:112] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1001 18:05:26.295] I1001 18:05:26.289224    8886 utils.go:113] GRPC request: 
I1001 18:05:26.295] I1001 18:05:26.289236    8886 controllerserver.go:415] Using default ControllerGetCapabilities
I1001 18:05:26.295] I1001 18:05:26.289243    8886 utils.go:119] GRPC response: capabilities:<rpc:<type:CREATE_DELETE_VOLUME > > capabilities:<rpc:<type:PUBLISH_UNPUBLISH_VOLUME > > capabilities:<rpc:<type:CREATE_DELETE_SNAPSHOT > > capabilities:<rpc:<type:LIST_SNAPSHOTS > > 
I1001 18:05:26.295] I1001 18:05:26.290117    8886 utils.go:112] GRPC call: /csi.v1.Controller/ControllerPublishVolume
I1001 18:05:26.296] I1001 18:05:26.290155    8886 utils.go:113] GRPC request: 
I1001 18:05:26.296] I1001 18:05:26.290168    8886 controllerserver.go:294] ControllerPublishVolume: called with args {VolumeId: NodeId: VolumeCapability:<nil> Readonly:false Secrets:map[] VolumeContext:map[] XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
I1001 18:05:26.296] E1001 18:05:26.290194    8886 utils.go:117] GRPC error: rpc error: code = InvalidArgument desc = Volume ID not provided
I1001 18:05:26.296] •
I1001 18:05:26.297] ------------------------------
I1001 18:05:26.297] Controller Service ControllerPublishVolume 
I1001 18:05:26.297]   should fail when no node id is provided
I1001 18:05:26.297]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:735
I1001 18:05:26.297] STEP: reusing connection to CSI driver at unix:///tmp/csi.sock
I1001 18:05:26.298] STEP: creating mount and staging directories
I1001 18:05:26.298] I1001 18:05:26.290750    8886 utils.go:112] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1001 18:05:26.298] I1001 18:05:26.290775    8886 utils.go:113] GRPC request: 
I1001 18:05:26.298] I1001 18:05:26.290786    8886 controllerserver.go:415] Using default ControllerGetCapabilities
I1001 18:05:26.298] I1001 18:05:26.290792    8886 utils.go:119] GRPC response: capabilities:<rpc:<type:CREATE_DELETE_VOLUME > > capabilities:<rpc:<type:PUBLISH_UNPUBLISH_VOLUME > > capabilities:<rpc:<type:CREATE_DELETE_SNAPSHOT > > capabilities:<rpc:<type:LIST_SNAPSHOTS > > 
I1001 18:05:26.299] I1001 18:05:26.291235    8886 utils.go:112] GRPC call: /csi.v1.Controller/ControllerPublishVolume
I1001 18:05:26.299] I1001 18:05:26.291261    8886 utils.go:113] GRPC request: volume_id:"id" 
I1001 18:05:26.299] I1001 18:05:26.291269    8886 controllerserver.go:294] ControllerPublishVolume: called with args {VolumeId:id NodeId: VolumeCapability:<nil> Readonly:false Secrets:map[] VolumeContext:map[] XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
I1001 18:05:26.299] E1001 18:05:26.291290    8886 utils.go:117] GRPC error: rpc error: code = InvalidArgument desc = Volume capability not provided
I1001 18:05:26.300] •
I1001 18:05:26.300] ------------------------------
I1001 18:05:26.300] Controller Service ControllerPublishVolume 
I1001 18:05:26.300]   should fail when no volume capability is provided
I1001 18:05:26.300]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:751
I1001 18:05:26.301] STEP: reusing connection to CSI driver at unix:///tmp/csi.sock
I1001 18:05:26.301] STEP: creating mount and staging directories
I1001 18:05:26.301] I1001 18:05:26.291747    8886 utils.go:112] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1001 18:05:26.301] I1001 18:05:26.291769    8886 utils.go:113] GRPC request: 
I1001 18:05:26.301] I1001 18:05:26.291777    8886 controllerserver.go:415] Using default ControllerGetCapabilities
I1001 18:05:26.302] I1001 18:05:26.291783    8886 utils.go:119] GRPC response: capabilities:<rpc:<type:CREATE_DELETE_VOLUME > > capabilities:<rpc:<type:PUBLISH_UNPUBLISH_VOLUME > > capabilities:<rpc:<type:CREATE_DELETE_SNAPSHOT > > capabilities:<rpc:<type:LIST_SNAPSHOTS > > 
I1001 18:05:26.302] I1001 18:05:26.292292    8886 utils.go:112] GRPC call: /csi.v1.Controller/ControllerPublishVolume
I1001 18:05:26.302] I1001 18:05:26.292318    8886 utils.go:113] GRPC request: volume_id:"id" node_id:"fakenode" 
I1001 18:05:26.302] I1001 18:05:26.292329    8886 controllerserver.go:294] ControllerPublishVolume: called with args {VolumeId:id NodeId:fakenode VolumeCapability:<nil> Readonly:false Secrets:map[] VolumeContext:map[] XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
I1001 18:05:26.303] E1001 18:05:26.292354    8886 utils.go:117] GRPC error: rpc error: code = InvalidArgument desc = Volume capability not provided
I1001 18:05:26.303] •
I1001 18:05:26.303] ------------------------------
I1001 18:05:26.303] Controller Service ControllerPublishVolume 
I1001 18:05:26.303]   should return appropriate values (no optional values added)
I1001 18:05:26.303]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:768
I1001 18:05:26.304] STEP: reusing connection to CSI driver at unix:///tmp/csi.sock
... skipping 11 lines ...
I1001 18:05:27.121] I1001 18:05:27.120575    8886 controllerserver.go:222] create azure disk(sanity-controller-publish-7632817E-817F5FAA) account type(Standard_LRS) rg(azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc) location() size(1) successfully
I1001 18:05:27.121] I1001 18:05:27.120585    8886 utils.go:119] GRPC response: volume:<volume_id:"/subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc/providers/Microsoft.Compute/disks/sanity-controller-publish-7632817E-817F5FAA" accessible_topology:<segments:<key:"topology.disk.csi.azure.com/zone" value:"" > > > 
I1001 18:05:27.121] STEP: getting a node id
I1001 18:05:27.122] I1001 18:05:27.121174    8886 utils.go:112] GRPC call: /csi.v1.Node/NodeGetInfo
I1001 18:05:27.122] I1001 18:05:27.121200    8886 utils.go:113] GRPC request: 
I1001 18:05:27.122] I1001 18:05:27.121208    8886 nodeserver.go:281] Using default NodeGetInfo
I1001 18:05:27.210] I1001 18:05:27.210119    8886 azure_wrap.go:222] Virtual machine "CSINode" not found with message: "compute.VirtualMachinesClient#Get: Failure responding to request: StatusCode=404 -- Original Error: autorest/azure: Service returned an error. Status=404 Code=\"ResourceNotFound\" Message=\"The Resource 'Microsoft.Compute/virtualMachines/CSINode' under resource group 'azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc' was not found.\""
I1001 18:05:27.210] E1001 18:05:27.210154    8886 azure_standard.go:392] as.GetInstanceTypeByNodeName(CSINode) failed: as.getVirtualMachine(CSINode) err=instance not found
I1001 18:05:27.211] W1001 18:05:27.210171    8886 nodeserver.go:290] Failed to get instance type from Azure cloud provider, nodeName: CSINode, error: instance not found
I1001 18:05:27.323] I1001 18:05:27.323706    8886 utils.go:119] GRPC response: node_id:"CSINode" max_volumes_per_node:16 
I1001 18:05:27.324] STEP: calling controllerpublish on that volume
I1001 18:05:27.324] I1001 18:05:27.324276    8886 utils.go:112] GRPC call: /csi.v1.Controller/ControllerPublishVolume
I1001 18:05:27.324] I1001 18:05:27.324300    8886 utils.go:113] GRPC request: volume_id:"/subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc/providers/Microsoft.Compute/disks/sanity-controller-publish-7632817E-817F5FAA" node_id:"CSINode" volume_capability:<mount:<> access_mode:<mode:SINGLE_NODE_WRITER > > 
I1001 18:05:27.325] I1001 18:05:27.324329    8886 controllerserver.go:294] ControllerPublishVolume: called with args {VolumeId:/subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc/providers/Microsoft.Compute/disks/sanity-controller-publish-7632817E-817F5FAA NodeId:CSINode VolumeCapability:mount:<> access_mode:<mode:SINGLE_NODE_WRITER >  Readonly:false Secrets:map[] VolumeContext:map[] XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
I1001 18:05:27.425] I1001 18:05:27.424731    8886 controllerserver.go:326] GetDiskLun returned: <nil>. Initiating attaching volume "/subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc/providers/Microsoft.Compute/disks/sanity-controller-publish-7632817E-817F5FAA" to node "CSINode".
I1001 18:05:27.506] I1001 18:05:27.505731    8886 azure_wrap.go:222] Virtual machine "CSINode" not found with message: "compute.VirtualMachinesClient#Get: Failure responding to request: StatusCode=404 -- Original Error: autorest/azure: Service returned an error. Status=404 Code=\"ResourceNotFound\" Message=\"The Resource 'Microsoft.Compute/virtualMachines/CSINode' under resource group 'azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc' was not found.\""
I1001 18:05:27.506] E1001 18:05:27.505793    8886 azure_controller_common.go:193] error of getting data disks for node "CSINode": instance not found
I1001 18:05:27.507] E1001 18:05:27.505810    8886 utils.go:117] GRPC error: rpc error: code = NotFound desc = failed to get azure instance id for node "CSINode" (instance not found)
I1001 18:05:27.507] cleanup: deleting sanity-controller-publish-7632817E-817F5FAA = /subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc/providers/Microsoft.Compute/disks/sanity-controller-publish-7632817E-817F5FAA
I1001 18:05:27.507] I1001 18:05:27.507125    8886 utils.go:112] GRPC call: /csi.v1.Node/NodeUnpublishVolume
I1001 18:05:27.508] I1001 18:05:27.507153    8886 utils.go:113] GRPC request: volume_id:"/subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc/providers/Microsoft.Compute/disks/sanity-controller-publish-7632817E-817F5FAA" target_path:"/tmp/csi" 
I1001 18:05:27.508] I1001 18:05:27.507169    8886 nodeserver.go:260] NodeUnpublishVolume: unmounting volume /subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc/providers/Microsoft.Compute/disks/sanity-controller-publish-7632817E-817F5FAA on /tmp/csi
I1001 18:05:27.508] I1001 18:05:27.507183    8886 mount_linux.go:209] Unmounting /tmp/csi
I1001 18:05:27.512] E1001 18:05:27.512646    8886 utils.go:117] GRPC error: rpc error: code = Internal desc = Unmount failed: exit status 32
I1001 18:05:27.513] Unmounting arguments: /tmp/csi
I1001 18:05:27.513] Output: umount: /tmp/csi: not mounted
I1001 18:05:27.513] 
I1001 18:05:27.513] cleanup: warning: NodeUnpublishVolume: rpc error: code = Internal desc = Unmount failed: exit status 32
I1001 18:05:27.514] Unmounting arguments: /tmp/csi
I1001 18:05:27.514] Output: umount: /tmp/csi: not mounted
I1001 18:05:27.514] 
I1001 18:05:27.514] I1001 18:05:27.513165    8886 utils.go:112] GRPC call: /csi.v1.Controller/DeleteVolume
I1001 18:05:27.515] I1001 18:05:27.513195    8886 utils.go:113] GRPC request: volume_id:"/subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc/providers/Microsoft.Compute/disks/sanity-controller-publish-7632817E-817F5FAA" 
I1001 18:05:27.515] I1001 18:05:27.513205    8886 controllerserver.go:277] deleting azure disk(/subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc/providers/Microsoft.Compute/disks/sanity-controller-publish-7632817E-817F5FAA)
... skipping 6 lines ...
I1001 18:05:32.962] /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/tests.go:44
I1001 18:05:32.963]   ControllerPublishVolume
I1001 18:05:32.963]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:713
I1001 18:05:32.963]     should return appropriate values (no optional values added) [It]
I1001 18:05:32.963]     /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:768
I1001 18:05:32.964] 
I1001 18:05:32.964]     Unexpected error:
I1001 18:05:32.964]         <*status.statusError | 0xc0004e1360>: {
I1001 18:05:32.964]             Code: 5,
I1001 18:05:32.964]             Message: "failed to get azure instance id for node \"CSINode\" (instance not found)",
I1001 18:05:32.965]             Details: nil,
I1001 18:05:32.965]             XXX_NoUnkeyedLiteral: {},
I1001 18:05:32.965]             XXX_unrecognized: nil,
I1001 18:05:32.965]             XXX_sizecache: 0,
I1001 18:05:32.966]         }
I1001 18:05:32.966]         rpc error: code = NotFound desc = failed to get azure instance id for node "CSINode" (instance not found)
I1001 18:05:32.966]     occurred
I1001 18:05:32.966] 
I1001 18:05:32.967]     /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:826
I1001 18:05:32.967] ------------------------------
I1001 18:05:32.967] Controller Service ControllerPublishVolume 
I1001 18:05:32.967]   should fail when the volume does not exist
I1001 18:05:32.967]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:857
I1001 18:05:32.968] STEP: reusing connection to CSI driver at unix:///tmp/csi.sock
I1001 18:05:32.968] STEP: creating mount and staging directories
I1001 18:05:32.968] I1001 18:05:32.960694    8886 utils.go:112] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1001 18:05:32.968] I1001 18:05:32.960730    8886 utils.go:113] GRPC request: 
I1001 18:05:32.969] I1001 18:05:32.960738    8886 controllerserver.go:415] Using default ControllerGetCapabilities
I1001 18:05:32.969] I1001 18:05:32.960743    8886 utils.go:119] GRPC response: capabilities:<rpc:<type:CREATE_DELETE_VOLUME > > capabilities:<rpc:<type:PUBLISH_UNPUBLISH_VOLUME > > capabilities:<rpc:<type:CREATE_DELETE_SNAPSHOT > > capabilities:<rpc:<type:LIST_SNAPSHOTS > > 
I1001 18:05:32.969] STEP: calling controller publish on a non-existent volume
I1001 18:05:32.970] I1001 18:05:32.962799    8886 utils.go:112] GRPC call: /csi.v1.Controller/ControllerPublishVolume
I1001 18:05:32.970] I1001 18:05:32.962850    8886 utils.go:113] GRPC request: volume_id:"some-vol-id" node_id:"some-node-id" volume_capability:<mount:<> access_mode:<mode:SINGLE_NODE_WRITER > > 
I1001 18:05:32.970] I1001 18:05:32.962917    8886 controllerserver.go:294] ControllerPublishVolume: called with args {VolumeId:some-vol-id NodeId:some-node-id VolumeCapability:mount:<> access_mode:<mode:SINGLE_NODE_WRITER >  Readonly:false Secrets:map[] VolumeContext:map[] XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
I1001 18:05:32.971] E1001 18:05:32.962981    8886 utils.go:117] GRPC error: rpc error: code = NotFound desc = Volume not found, failed with error: could not get disk name from some-vol-id, correct format: .*/subscriptions/(?:.*)/resourceGroups/(?:.*)/providers/Microsoft.Compute/disks/(.+)
I1001 18:05:32.971] •
I1001 18:05:32.971] ------------------------------
I1001 18:05:32.971] Controller Service ControllerPublishVolume 
I1001 18:05:32.971]   should fail when the node does not exist
I1001 18:05:32.972]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:886
I1001 18:05:32.972] STEP: reusing connection to CSI driver at unix:///tmp/csi.sock
I1001 18:05:32.972] STEP: creating mount and staging directories
I1001 18:05:32.972] I1001 18:05:32.963446    8886 utils.go:112] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1001 18:05:32.973] I1001 18:05:32.963478    8886 utils.go:113] GRPC request: 
I1001 18:05:32.973] I1001 18:05:32.963485    8886 controllerserver.go:415] Using default ControllerGetCapabilities
... skipping 8 lines ...
I1001 18:05:33.671] I1001 18:05:33.670130    8886 utils.go:119] GRPC response: volume:<volume_id:"/subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc/providers/Microsoft.Compute/disks/sanity-controller-wrong-node-7632817E-817F5FAA" accessible_topology:<segments:<key:"topology.disk.csi.azure.com/zone" value:"" > > > 
I1001 18:05:33.671] STEP: calling controllerpublish on that volume
I1001 18:05:33.672] I1001 18:05:33.670939    8886 utils.go:112] GRPC call: /csi.v1.Controller/ControllerPublishVolume
I1001 18:05:33.672] I1001 18:05:33.670983    8886 utils.go:113] GRPC request: volume_id:"/subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc/providers/Microsoft.Compute/disks/sanity-controller-wrong-node-7632817E-817F5FAA" node_id:"some-fake-node-id" volume_capability:<mount:<> access_mode:<mode:SINGLE_NODE_WRITER > > 
I1001 18:05:33.672] I1001 18:05:33.670999    8886 controllerserver.go:294] ControllerPublishVolume: called with args {VolumeId:/subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc/providers/Microsoft.Compute/disks/sanity-controller-wrong-node-7632817E-817F5FAA NodeId:some-fake-node-id VolumeCapability:mount:<> access_mode:<mode:SINGLE_NODE_WRITER >  Readonly:false Secrets:map[] VolumeContext:map[] XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
I1001 18:05:33.771] I1001 18:05:33.771528    8886 controllerserver.go:326] GetDiskLun returned: <nil>. Initiating attaching volume "/subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc/providers/Microsoft.Compute/disks/sanity-controller-wrong-node-7632817E-817F5FAA" to node "some-fake-node-id".
I1001 18:05:33.881] I1001 18:05:33.881143    8886 azure_wrap.go:222] Virtual machine "some-fake-node-id" not found with message: "compute.VirtualMachinesClient#Get: Failure responding to request: StatusCode=404 -- Original Error: autorest/azure: Service returned an error. Status=404 Code=\"ResourceNotFound\" Message=\"The Resource 'Microsoft.Compute/virtualMachines/some-fake-node-id' under resource group 'azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc' was not found.\""
I1001 18:05:33.881] E1001 18:05:33.881192    8886 azure_controller_common.go:193] error of getting data disks for node "some-fake-node-id": instance not found
I1001 18:05:33.882] E1001 18:05:33.881217    8886 utils.go:117] GRPC error: rpc error: code = NotFound desc = failed to get azure instance id for node "some-fake-node-id" (instance not found)
I1001 18:05:33.882] STEP: cleaning up deleting the volume
I1001 18:05:33.882] I1001 18:05:33.881747    8886 utils.go:112] GRPC call: /csi.v1.Controller/DeleteVolume
I1001 18:05:33.883] I1001 18:05:33.881774    8886 utils.go:113] GRPC request: volume_id:"/subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc/providers/Microsoft.Compute/disks/sanity-controller-wrong-node-7632817E-817F5FAA" 
I1001 18:05:33.883] I1001 18:05:33.881788    8886 controllerserver.go:277] deleting azure disk(/subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc/providers/Microsoft.Compute/disks/sanity-controller-wrong-node-7632817E-817F5FAA)
I1001 18:05:34.270] I1001 18:05:34.270079    8886 azure_managedDiskController.go:195] azureDisk - deleted a managed disk: /subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc/providers/Microsoft.Compute/disks/sanity-controller-wrong-node-7632817E-817F5FAA
I1001 18:05:34.271] I1001 18:05:34.270131    8886 controllerserver.go:287] delete azure disk(/subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc/providers/Microsoft.Compute/disks/sanity-controller-wrong-node-7632817E-817F5FAA) successfully
I1001 18:05:34.271] I1001 18:05:34.270140    8886 utils.go:119] GRPC response: 
I1001 18:05:34.271] •
I1001 18:05:34.271] ------------------------------
I1001 18:05:34.272] Controller Service ControllerPublishVolume 
I1001 18:05:34.272]   should fail when the volume is already published but is incompatible
I1001 18:05:34.272]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:956
I1001 18:05:34.272] STEP: reusing connection to CSI driver at unix:///tmp/csi.sock
I1001 18:05:34.272] STEP: creating mount and staging directories
I1001 18:05:34.273] I1001 18:05:34.270729    8886 utils.go:112] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1001 18:05:34.273] I1001 18:05:34.270765    8886 utils.go:113] GRPC request: 
I1001 18:05:34.273] I1001 18:05:34.270775    8886 controllerserver.go:415] Using default ControllerGetCapabilities
... skipping 5 lines ...
I1001 18:05:34.275] 
I1001 18:05:34.275] S [SKIPPING] [0.002 seconds]
I1001 18:05:34.275] Controller Service
I1001 18:05:34.276] /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/tests.go:44
I1001 18:05:34.276]   ControllerPublishVolume
I1001 18:05:34.276]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:713
I1001 18:05:34.276]     should fail when the volume is already published but is incompatible [It]
I1001 18:05:34.277]     /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:956
I1001 18:05:34.277] 
I1001 18:05:34.277]     ControllerPublishVolume.readonly field not supported
I1001 18:05:34.277] 
I1001 18:05:34.278]     /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:958
I1001 18:05:34.278] ------------------------------
I1001 18:05:34.278] Controller Service ControllerUnpublishVolume 
I1001 18:05:34.278]   should fail when no volume id is provided
I1001 18:05:34.278]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:1066
I1001 18:05:34.279] STEP: reusing connection to CSI driver at unix:///tmp/csi.sock
I1001 18:05:34.279] STEP: creating mount and staging directories
I1001 18:05:34.279] I1001 18:05:34.272745    8886 utils.go:112] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1001 18:05:34.279] I1001 18:05:34.272770    8886 utils.go:113] GRPC request: 
I1001 18:05:34.280] I1001 18:05:34.272775    8886 controllerserver.go:415] Using default ControllerGetCapabilities
I1001 18:05:34.280] I1001 18:05:34.272780    8886 utils.go:119] GRPC response: capabilities:<rpc:<type:CREATE_DELETE_VOLUME > > capabilities:<rpc:<type:PUBLISH_UNPUBLISH_VOLUME > > capabilities:<rpc:<type:CREATE_DELETE_SNAPSHOT > > capabilities:<rpc:<type:LIST_SNAPSHOTS > > 
I1001 18:05:34.280] I1001 18:05:34.273554    8886 utils.go:112] GRPC call: /csi.v1.Controller/ControllerUnpublishVolume
I1001 18:05:34.280] I1001 18:05:34.273596    8886 utils.go:113] GRPC request: 
I1001 18:05:34.281] I1001 18:05:34.273608    8886 controllerserver.go:360] ControllerUnpublishVolume: called with args {VolumeId: NodeId: Secrets:map[] XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
I1001 18:05:34.281] E1001 18:05:34.273652    8886 utils.go:117] GRPC error: rpc error: code = InvalidArgument desc = Volume ID not provided
I1001 18:05:34.281] •
I1001 18:05:34.281] ------------------------------
I1001 18:05:34.282] Controller Service ControllerUnpublishVolume 
I1001 18:05:34.282]   should return appropriate values (no optional values added)
I1001 18:05:34.282]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:1081
I1001 18:05:34.282] STEP: reusing connection to CSI driver at unix:///tmp/csi.sock
... skipping 11 lines ...
I1001 18:05:34.957] I1001 18:05:34.956646    8886 controllerserver.go:222] create azure disk(sanity-controller-unpublish-7632817E-817F5FAA) account type(Standard_LRS) rg(azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc) location() size(1) successfully
I1001 18:05:34.957] I1001 18:05:34.956658    8886 utils.go:119] GRPC response: volume:<volume_id:"/subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc/providers/Microsoft.Compute/disks/sanity-controller-unpublish-7632817E-817F5FAA" accessible_topology:<segments:<key:"topology.disk.csi.azure.com/zone" value:"" > > > 
I1001 18:05:34.958] STEP: getting a node id
I1001 18:05:34.958] I1001 18:05:34.957428    8886 utils.go:112] GRPC call: /csi.v1.Node/NodeGetInfo
I1001 18:05:34.958] I1001 18:05:34.957464    8886 utils.go:113] GRPC request: 
I1001 18:05:34.958] I1001 18:05:34.957473    8886 nodeserver.go:281] Using default NodeGetInfo
I1001 18:05:35.039] I1001 18:05:35.038820    8886 azure_wrap.go:222] Virtual machine "CSINode" not found with message: "compute.VirtualMachinesClient#Get: Failure responding to request: StatusCode=404 -- Original Error: autorest/azure: Service returned an error. Status=404 Code=\"ResourceNotFound\" Message=\"The Resource 'Microsoft.Compute/virtualMachines/CSINode' under resource group 'azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc' was not found.\""
I1001 18:05:35.039] E1001 18:05:35.038873    8886 azure_standard.go:392] as.GetInstanceTypeByNodeName(CSINode) failed: as.getVirtualMachine(CSINode) err=instance not found
I1001 18:05:35.039] W1001 18:05:35.038884    8886 nodeserver.go:290] Failed to get instance type from Azure cloud provider, nodeName: CSINode, error: instance not found
I1001 18:05:35.040] I1001 18:05:35.038890    8886 utils.go:119] GRPC response: node_id:"CSINode" max_volumes_per_node:16 
I1001 18:05:35.040] STEP: calling controllerpublish on that volume
I1001 18:05:35.040] I1001 18:05:35.039531    8886 utils.go:112] GRPC call: /csi.v1.Controller/ControllerPublishVolume
I1001 18:05:35.040] I1001 18:05:35.039559    8886 utils.go:113] GRPC request: volume_id:"/subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc/providers/Microsoft.Compute/disks/sanity-controller-unpublish-7632817E-817F5FAA" node_id:"CSINode" volume_capability:<mount:<> access_mode:<mode:SINGLE_NODE_WRITER > > 
I1001 18:05:35.041] I1001 18:05:35.039578    8886 controllerserver.go:294] ControllerPublishVolume: called with args {VolumeId:/subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc/providers/Microsoft.Compute/disks/sanity-controller-unpublish-7632817E-817F5FAA NodeId:CSINode VolumeCapability:mount:<> access_mode:<mode:SINGLE_NODE_WRITER >  Readonly:false Secrets:map[] VolumeContext:map[] XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
I1001 18:05:35.138] I1001 18:05:35.138629    8886 controllerserver.go:326] GetDiskLun returned: <nil>. Initiating attaching volume "/subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc/providers/Microsoft.Compute/disks/sanity-controller-unpublish-7632817E-817F5FAA" to node "CSINode".
I1001 18:05:35.230] I1001 18:05:35.230103    8886 azure_wrap.go:222] Virtual machine "CSINode" not found with message: "compute.VirtualMachinesClient#Get: Failure responding to request: StatusCode=404 -- Original Error: autorest/azure: Service returned an error. Status=404 Code=\"ResourceNotFound\" Message=\"The Resource 'Microsoft.Compute/virtualMachines/CSINode' under resource group 'azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc' was not found.\""
I1001 18:05:35.230] E1001 18:05:35.230150    8886 azure_controller_common.go:193] error of getting data disks for node "CSINode": instance not found
I1001 18:05:35.231] E1001 18:05:35.230162    8886 utils.go:117] GRPC error: rpc error: code = NotFound desc = failed to get azure instance id for node "CSINode" (instance not found)
I1001 18:05:35.231] cleanup: deleting sanity-controller-unpublish-7632817E-817F5FAA = /subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc/providers/Microsoft.Compute/disks/sanity-controller-unpublish-7632817E-817F5FAA
I1001 18:05:35.231] I1001 18:05:35.231251    8886 utils.go:112] GRPC call: /csi.v1.Node/NodeUnpublishVolume
I1001 18:05:35.232] I1001 18:05:35.231287    8886 utils.go:113] GRPC request: volume_id:"/subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc/providers/Microsoft.Compute/disks/sanity-controller-unpublish-7632817E-817F5FAA" target_path:"/tmp/csi" 
I1001 18:05:35.232] I1001 18:05:35.231310    8886 nodeserver.go:260] NodeUnpublishVolume: unmounting volume /subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc/providers/Microsoft.Compute/disks/sanity-controller-unpublish-7632817E-817F5FAA on /tmp/csi
I1001 18:05:35.232] I1001 18:05:35.231342    8886 mount_linux.go:209] Unmounting /tmp/csi
I1001 18:05:35.234] E1001 18:05:35.233919    8886 utils.go:117] GRPC error: rpc error: code = Internal desc = Unmount failed: exit status 32
I1001 18:05:35.234] Unmounting arguments: /tmp/csi
I1001 18:05:35.234] Output: umount: /tmp/csi: not mounted
I1001 18:05:35.234] 
I1001 18:05:35.235] cleanup: warning: NodeUnpublishVolume: rpc error: code = Internal desc = Unmount failed: exit status 32
I1001 18:05:35.235] Unmounting arguments: /tmp/csi
I1001 18:05:35.235] Output: umount: /tmp/csi: not mounted
I1001 18:05:35.235] 
I1001 18:05:35.235] I1001 18:05:35.234473    8886 utils.go:112] GRPC call: /csi.v1.Controller/DeleteVolume
I1001 18:05:35.236] I1001 18:05:35.234503    8886 utils.go:113] GRPC request: volume_id:"/subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc/providers/Microsoft.Compute/disks/sanity-controller-unpublish-7632817E-817F5FAA" 
I1001 18:05:35.236] I1001 18:05:35.234518    8886 controllerserver.go:277] deleting azure disk(/subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc/providers/Microsoft.Compute/disks/sanity-controller-unpublish-7632817E-817F5FAA)
... skipping 6 lines ...
I1001 18:05:35.597] /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/tests.go:44
I1001 18:05:35.597]   ControllerUnpublishVolume
I1001 18:05:35.597]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:1059
I1001 18:05:35.598]     should return appropriate values (no optional values added) [It]
I1001 18:05:35.598]     /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:1081
I1001 18:05:35.598] 
I1001 18:05:35.598]     Unexpected error:
I1001 18:05:35.599]         <*status.statusError | 0xc0004e1bd0>: {
I1001 18:05:35.599]             Code: 5,
I1001 18:05:35.599]             Message: "failed to get azure instance id for node \"CSINode\" (instance not found)",
I1001 18:05:35.599]             Details: nil,
I1001 18:05:35.600]             XXX_NoUnkeyedLiteral: {},
I1001 18:05:35.600]             XXX_unrecognized: nil,
I1001 18:05:35.600]             XXX_sizecache: 0,
I1001 18:05:35.600]         }
I1001 18:05:35.601]         rpc error: code = NotFound desc = failed to get azure instance id for node "CSINode" (instance not found)
I1001 18:05:35.601]     occurred
I1001 18:05:35.601] 
I1001 18:05:35.602]     /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:1139
I1001 18:05:35.602] ------------------------------
I1001 18:05:35.602] CreateSnapshot [Controller Server] 
I1001 18:05:35.602]   should fail when no name is provided
I1001 18:05:35.603]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:1502
I1001 18:05:35.603] STEP: reusing connection to CSI driver at unix:///tmp/csi.sock
I1001 18:05:35.603] STEP: creating mount and staging directories
I1001 18:05:35.604] I1001 18:05:35.595778    8886 utils.go:112] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1001 18:05:35.604] I1001 18:05:35.595825    8886 utils.go:113] GRPC request: 
I1001 18:05:35.604] I1001 18:05:35.595835    8886 controllerserver.go:415] Using default ControllerGetCapabilities
I1001 18:05:35.604] I1001 18:05:35.595842    8886 utils.go:119] GRPC response: capabilities:<rpc:<type:CREATE_DELETE_VOLUME > > capabilities:<rpc:<type:PUBLISH_UNPUBLISH_VOLUME > > capabilities:<rpc:<type:CREATE_DELETE_SNAPSHOT > > capabilities:<rpc:<type:LIST_SNAPSHOTS > > 
I1001 18:05:35.605] I1001 18:05:35.596454    8886 utils.go:112] GRPC call: /csi.v1.Controller/CreateSnapshot
I1001 18:05:35.605] I1001 18:05:35.596489    8886 utils.go:113] GRPC request: source_volume_id:"testId" 
I1001 18:05:35.605] I1001 18:05:35.596501    8886 controllerserver.go:439] CreateSnapshot called with request {testId  map[] map[] {} [] 0}
I1001 18:05:35.606] E1001 18:05:35.596515    8886 utils.go:117] GRPC error: rpc error: code = InvalidArgument desc = Snapshot name must be provided
I1001 18:05:35.606] •
I1001 18:05:35.606] ------------------------------
I1001 18:05:35.606] CreateSnapshot [Controller Server] 
I1001 18:05:35.607]   should fail when no source volume id is provided
I1001 18:05:35.607]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:1519
I1001 18:05:35.607] STEP: reusing connection to CSI driver at unix:///tmp/csi.sock
I1001 18:05:35.607] STEP: creating mount and staging directories
I1001 18:05:35.608] I1001 18:05:35.596957    8886 utils.go:112] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1001 18:05:35.608] I1001 18:05:35.596988    8886 utils.go:113] GRPC request: 
I1001 18:05:35.608] I1001 18:05:35.596995    8886 controllerserver.go:415] Using default ControllerGetCapabilities
I1001 18:05:35.609] I1001 18:05:35.597001    8886 utils.go:119] GRPC response: capabilities:<rpc:<type:CREATE_DELETE_VOLUME > > capabilities:<rpc:<type:PUBLISH_UNPUBLISH_VOLUME > > capabilities:<rpc:<type:CREATE_DELETE_SNAPSHOT > > capabilities:<rpc:<type:LIST_SNAPSHOTS > > 
I1001 18:05:35.609] I1001 18:05:35.598327    8886 utils.go:112] GRPC call: /csi.v1.Controller/CreateSnapshot
I1001 18:05:35.609] I1001 18:05:35.598358    8886 utils.go:113] GRPC request: name:"name" 
I1001 18:05:35.609] I1001 18:05:35.598365    8886 controllerserver.go:439] CreateSnapshot called with request { name map[] map[] {} [] 0}
I1001 18:05:35.610] E1001 18:05:35.598382    8886 utils.go:117] GRPC error: rpc error: code = InvalidArgument desc = CreateSnapshot Source Volume ID must be provided
I1001 18:05:35.610] •
I1001 18:05:35.610] ------------------------------
I1001 18:05:35.610] CreateSnapshot [Controller Server] 
I1001 18:05:35.611]   should not fail when requesting to create a snapshot with already existing name and same SourceVolumeId.
I1001 18:05:35.611]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:1536
I1001 18:05:35.611] STEP: reusing connection to CSI driver at unix:///tmp/csi.sock
I1001 18:05:35.611] STEP: creating mount and staging directories
I1001 18:05:35.611] I1001 18:05:35.598892    8886 utils.go:112] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1001 18:05:35.612] I1001 18:05:35.598915    8886 utils.go:113] GRPC request: 
I1001 18:05:35.612] I1001 18:05:35.598922    8886 controllerserver.go:415] Using default ControllerGetCapabilities
... skipping 34 lines ...
I1001 18:05:58.421] I1001 18:05:58.420670    8886 controllerserver.go:287] delete azure disk(/subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc/providers/Microsoft.Compute/disks/CreateSnapshot-volume-1) successfully
I1001 18:05:58.421] I1001 18:05:58.420677    8886 utils.go:119] GRPC response: 
I1001 18:05:58.421] 
I1001 18:05:58.422] • [SLOW TEST:22.822 seconds]
I1001 18:05:58.422] CreateSnapshot [Controller Server]
I1001 18:05:58.422] /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/tests.go:44
I1001 18:05:58.422]   should not fail when requesting to create a snapshot with already existing name and same SourceVolumeId.
I1001 18:05:58.422]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:1536
I1001 18:05:58.422] ------------------------------
I1001 18:05:58.423] CreateSnapshot [Controller Server] 
I1001 18:05:58.423]   should fail when requesting to create a snapshot with already existing name and different SourceVolumeId.
I1001 18:05:58.423]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:1566
I1001 18:05:58.423] STEP: reusing connection to CSI driver at unix:///tmp/csi.sock
I1001 18:05:58.423] STEP: creating mount and staging directories
I1001 18:05:58.424] I1001 18:05:58.421320    8886 utils.go:112] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1001 18:05:58.424] I1001 18:05:58.421346    8886 utils.go:113] GRPC request: 
I1001 18:05:58.424] I1001 18:05:58.421353    8886 controllerserver.go:415] Using default ControllerGetCapabilities
... skipping 22 lines ...
I1001 18:06:10.697] I1001 18:06:10.696083    8886 utils.go:119] GRPC response: volume:<capacity_bytes:10737418240 volume_id:"/subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc/providers/Microsoft.Compute/disks/CreateSnapshot-volume-3" accessible_topology:<segments:<key:"topology.disk.csi.azure.com/zone" value:"" > > > 
I1001 18:06:10.697] STEP: creating a snapshot with the same name but different volume source id
I1001 18:06:10.697] I1001 18:06:10.696878    8886 utils.go:112] GRPC call: /csi.v1.Controller/CreateSnapshot
I1001 18:06:10.698] I1001 18:06:10.696908    8886 utils.go:113] GRPC request: source_volume_id:"/subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc/providers/Microsoft.Compute/disks/CreateSnapshot-volume-3" name:"CreateSnapshot-snapshot-2" 
I1001 18:06:10.698] I1001 18:06:10.696923    8886 controllerserver.go:439] CreateSnapshot called with request {/subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc/providers/Microsoft.Compute/disks/CreateSnapshot-volume-3 CreateSnapshot-snapshot-2 map[] map[] {} [] 0}
I1001 18:06:10.698] I1001 18:06:10.696950    8886 controllerserver.go:463] begin to create snapshot(CreateSnapshot-snapshot-2) under rg(azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc)
I1001 18:06:10.952] E1001 18:06:10.952354    8886 utils.go:117] GRPC error: rpc error: code = AlreadyExists desc = request snapshot(CreateSnapshot-snapshot-2) under rg(azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc) already exists, but the SourceVolumeId is different, error details: compute.SnapshotsClient#CreateOrUpdate: Failure sending request: StatusCode=400 -- Original Error: Code="BadRequest" Message="Changing property 'sourceResourceId' is not allowed for existing disk 'CreateSnapshot-snapshot-2'."
I1001 18:06:10.953] STEP: cleaning up deleting the snapshot
I1001 18:06:10.953] I1001 18:06:10.952980    8886 utils.go:112] GRPC call: /csi.v1.Controller/DeleteSnapshot
I1001 18:06:10.953] I1001 18:06:10.953041    8886 utils.go:113] GRPC request: snapshot_id:"/subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc/providers/Microsoft.Compute/snapshots/CreateSnapshot-snapshot-2" 
I1001 18:06:10.954] I1001 18:06:10.953088    8886 controllerserver.go:491] DeleteSnapshot called with request {/subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc/providers/Microsoft.Compute/snapshots/CreateSnapshot-snapshot-2 map[] {} [] 0}
I1001 18:06:10.954] I1001 18:06:10.953160    8886 controllerserver.go:503] begin to delete snapshot(CreateSnapshot-snapshot-2) under rg(azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc)
I1001 18:06:16.393] I1001 18:06:16.393454    8886 controllerserver.go:512] delete snapshot(CreateSnapshot-snapshot-2) under rg(azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc) successfully
... skipping 6 lines ...
I1001 18:06:21.868] I1001 18:06:21.867921    8886 controllerserver.go:287] delete azure disk(/subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc/providers/Microsoft.Compute/disks/CreateSnapshot-volume-2) successfully
I1001 18:06:21.869] I1001 18:06:21.867936    8886 utils.go:119] GRPC response: 
I1001 18:06:21.869] 
I1001 18:06:21.869] • [SLOW TEST:23.447 seconds]
I1001 18:06:21.869] CreateSnapshot [Controller Server]
I1001 18:06:21.870] /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/tests.go:44
I1001 18:06:21.870]   should fail when requesting to create a snapshot with already existing name and different SourceVolumeId.
I1001 18:06:21.870]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:1566
I1001 18:06:21.871] ------------------------------
I1001 18:06:21.871] CreateSnapshot [Controller Server] 
I1001 18:06:21.871]   should not fail when creating snapshot with maximum-length name
I1001 18:06:21.871]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:1601
I1001 18:06:21.872] STEP: reusing connection to CSI driver at unix:///tmp/csi.sock
I1001 18:06:21.872] STEP: creating mount and staging directories
I1001 18:06:21.872] I1001 18:06:21.868751    8886 utils.go:112] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1001 18:06:21.872] I1001 18:06:21.868802    8886 utils.go:113] GRPC request: 
I1001 18:06:21.873] I1001 18:06:21.868814    8886 controllerserver.go:415] Using default ControllerGetCapabilities
... skipping 36 lines ...
I1001 18:06:56.882] I1001 18:06:56.881356    8886 controllerserver.go:287] delete azure disk(/subscriptions/940f88ce-a64b-4e73-a258-9931349b9789/resourceGroups/azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc/providers/Microsoft.Compute/disks/CreateSnapshot-volume-3) successfully
I1001 18:06:56.882] I1001 18:06:56.881370    8886 utils.go:119] GRPC response: 
I1001 18:06:56.882] 
I1001 18:06:56.883] • [SLOW TEST:35.013 seconds]
I1001 18:06:56.883] CreateSnapshot [Controller Server]
I1001 18:06:56.883] /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/tests.go:44
I1001 18:06:56.884]   should not fail when creating snapshot with maximum-length name
I1001 18:06:56.884]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:1601
I1001 18:06:56.884] ------------------------------
I1001 18:06:56.885] Node Service NodeGetCapabilities 
I1001 18:06:56.885]   should return appropriate capabilities
I1001 18:06:56.885]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:107
I1001 18:06:56.885] STEP: reusing connection to CSI driver at unix:///tmp/csi.sock
... skipping 31 lines ...
I1001 18:06:56.892] I1001 18:06:56.885708    8886 identityserver.go:59] Using default capabilities
I1001 18:06:56.892] I1001 18:06:56.885714    8886 utils.go:119] GRPC response: capabilities:<service:<type:CONTROLLER_SERVICE > > 
I1001 18:06:56.892] I1001 18:06:56.886219    8886 utils.go:112] GRPC call: /csi.v1.Node/NodeGetInfo
I1001 18:06:56.893] I1001 18:06:56.886250    8886 utils.go:113] GRPC request: 
I1001 18:06:56.893] I1001 18:06:56.886259    8886 nodeserver.go:281] Using default NodeGetInfo
I1001 18:06:56.893] I1001 18:06:56.886301    8886 expiration_cache.go:101] Entry CSINode: &{key:CSINode data:<nil> lock:{state:0 sema:0}} has expired
I1001 18:06:57.016] I1001 18:06:57.015996    8886 azure_wrap.go:222] Virtual machine "CSINode" not found with message: "compute.VirtualMachinesClient#Get: Failure responding to request: StatusCode=404 -- Original Error: autorest/azure: Service returned an error. Status=404 Code=\"ResourceNotFound\" Message=\"The Resource 'Microsoft.Compute/virtualMachines/CSINode' under resource group 'azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc' was not found.\""
I1001 18:06:57.016] E1001 18:06:57.016036    8886 azure_standard.go:392] as.GetInstanceTypeByNodeName(CSINode) failed: as.getVirtualMachine(CSINode) err=instance not found
I1001 18:06:57.017] W1001 18:06:57.016047    8886 nodeserver.go:290] Failed to get instance type from Azure cloud provider, nodeName: CSINode, error: instance not found
I1001 18:06:57.017] I1001 18:06:57.016053    8886 utils.go:119] GRPC response: node_id:"CSINode" max_volumes_per_node:16 
I1001 18:06:57.017] •
I1001 18:06:57.017] ------------------------------
I1001 18:06:57.018] Node Service NodePublishVolume 
I1001 18:06:57.018]   should fail when no volume id is provided
I1001 18:06:57.018]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:158
I1001 18:06:57.019] STEP: reusing connection to CSI driver at unix:///tmp/csi.sock
I1001 18:06:57.019] STEP: creating mount and staging directories
I1001 18:06:57.019] I1001 18:06:57.016602    8886 utils.go:112] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1001 18:06:57.019] I1001 18:06:57.016619    8886 utils.go:113] GRPC request: 
I1001 18:06:57.020] I1001 18:06:57.016624    8886 controllerserver.go:415] Using default ControllerGetCapabilities
I1001 18:06:57.020] I1001 18:06:57.016630    8886 utils.go:119] GRPC response: capabilities:<rpc:<type:CREATE_DELETE_VOLUME > > capabilities:<rpc:<type:PUBLISH_UNPUBLISH_VOLUME > > capabilities:<rpc:<type:CREATE_DELETE_SNAPSHOT > > capabilities:<rpc:<type:LIST_SNAPSHOTS > > 
I1001 18:06:57.020] I1001 18:06:57.017140    8886 utils.go:112] GRPC call: /csi.v1.Node/NodeGetCapabilities
I1001 18:06:57.021] I1001 18:06:57.017168    8886 utils.go:113] GRPC request: 
I1001 18:06:57.021] I1001 18:06:57.017176    8886 nodeserver.go:272] Using default NodeGetCapabilities
I1001 18:06:57.021] I1001 18:06:57.017182    8886 utils.go:119] GRPC response: capabilities:<rpc:<type:STAGE_UNSTAGE_VOLUME > > 
I1001 18:06:57.021] I1001 18:06:57.017919    8886 utils.go:112] GRPC call: /csi.v1.Node/NodePublishVolume
I1001 18:06:57.022] I1001 18:06:57.017986    8886 utils.go:113] GRPC request: 
I1001 18:06:57.022] E1001 18:06:57.017996    8886 utils.go:117] GRPC error: rpc error: code = InvalidArgument desc = Volume capability missing in request
I1001 18:06:57.022] •
I1001 18:06:57.022] ------------------------------
I1001 18:06:57.023] Node Service NodePublishVolume 
I1001 18:06:57.023]   should fail when no target path is provided
I1001 18:06:57.023]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:172
I1001 18:06:57.023] STEP: reusing connection to CSI driver at unix:///tmp/csi.sock
I1001 18:06:57.024] STEP: creating mount and staging directories
I1001 18:06:57.024] I1001 18:06:57.018545    8886 utils.go:112] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1001 18:06:57.024] I1001 18:06:57.018580    8886 utils.go:113] GRPC request: 
I1001 18:06:57.024] I1001 18:06:57.018590    8886 controllerserver.go:415] Using default ControllerGetCapabilities
I1001 18:06:57.025] I1001 18:06:57.018598    8886 utils.go:119] GRPC response: capabilities:<rpc:<type:CREATE_DELETE_VOLUME > > capabilities:<rpc:<type:PUBLISH_UNPUBLISH_VOLUME > > capabilities:<rpc:<type:CREATE_DELETE_SNAPSHOT > > capabilities:<rpc:<type:LIST_SNAPSHOTS > > 
I1001 18:06:57.025] I1001 18:06:57.019111    8886 utils.go:112] GRPC call: /csi.v1.Node/NodeGetCapabilities
I1001 18:06:57.025] I1001 18:06:57.019134    8886 utils.go:113] GRPC request: 
I1001 18:06:57.025] I1001 18:06:57.019141    8886 nodeserver.go:272] Using default NodeGetCapabilities
I1001 18:06:57.026] I1001 18:06:57.019148    8886 utils.go:119] GRPC response: capabilities:<rpc:<type:STAGE_UNSTAGE_VOLUME > > 
I1001 18:06:57.026] I1001 18:06:57.019606    8886 utils.go:112] GRPC call: /csi.v1.Node/NodePublishVolume
I1001 18:06:57.026] I1001 18:06:57.019634    8886 utils.go:113] GRPC request: volume_id:"id" 
I1001 18:06:57.027] E1001 18:06:57.019640    8886 utils.go:117] GRPC error: rpc error: code = InvalidArgument desc = Volume capability missing in request
I1001 18:06:57.027] •
I1001 18:06:57.027] ------------------------------
I1001 18:06:57.027] Node Service NodePublishVolume 
I1001 18:06:57.028]   should fail when no volume capability is provided
I1001 18:06:57.028]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:187
I1001 18:06:57.028] STEP: reusing connection to CSI driver at unix:///tmp/csi.sock
I1001 18:06:57.028] STEP: creating mount and staging directories
I1001 18:06:57.029] I1001 18:06:57.020008    8886 utils.go:112] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1001 18:06:57.029] I1001 18:06:57.020030    8886 utils.go:113] GRPC request: 
I1001 18:06:57.029] I1001 18:06:57.020038    8886 controllerserver.go:415] Using default ControllerGetCapabilities
I1001 18:06:57.030] I1001 18:06:57.020045    8886 utils.go:119] GRPC response: capabilities:<rpc:<type:CREATE_DELETE_VOLUME > > capabilities:<rpc:<type:PUBLISH_UNPUBLISH_VOLUME > > capabilities:<rpc:<type:CREATE_DELETE_SNAPSHOT > > capabilities:<rpc:<type:LIST_SNAPSHOTS > > 
I1001 18:06:57.030] I1001 18:06:57.020470    8886 utils.go:112] GRPC call: /csi.v1.Node/NodeGetCapabilities
I1001 18:06:57.030] I1001 18:06:57.020492    8886 utils.go:113] GRPC request: 
I1001 18:06:57.031] I1001 18:06:57.020503    8886 nodeserver.go:272] Using default NodeGetCapabilities
I1001 18:06:57.031] I1001 18:06:57.020510    8886 utils.go:119] GRPC response: capabilities:<rpc:<type:STAGE_UNSTAGE_VOLUME > > 
I1001 18:06:57.031] I1001 18:06:57.021037    8886 utils.go:112] GRPC call: /csi.v1.Node/NodePublishVolume
I1001 18:06:57.031] I1001 18:06:57.021072    8886 utils.go:113] GRPC request: volume_id:"id" target_path:"/tmp/csi" 
I1001 18:06:57.032] E1001 18:06:57.021094    8886 utils.go:117] GRPC error: rpc error: code = InvalidArgument desc = Volume capability missing in request
I1001 18:06:57.032] •
I1001 18:06:57.032] ------------------------------
I1001 18:06:57.032] Node Service NodeUnpublishVolume 
I1001 18:06:57.032]   should fail when no volume id is provided
I1001 18:06:57.032]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:205
I1001 18:06:57.033] STEP: reusing connection to CSI driver at unix:///tmp/csi.sock
I1001 18:06:57.033] STEP: creating mount and staging directories
I1001 18:06:57.033] I1001 18:06:57.021493    8886 utils.go:112] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1001 18:06:57.033] I1001 18:06:57.021520    8886 utils.go:113] GRPC request: 
I1001 18:06:57.034] I1001 18:06:57.021528    8886 controllerserver.go:415] Using default ControllerGetCapabilities
I1001 18:06:57.034] I1001 18:06:57.021535    8886 utils.go:119] GRPC response: capabilities:<rpc:<type:CREATE_DELETE_VOLUME > > capabilities:<rpc:<type:PUBLISH_UNPUBLISH_VOLUME > > capabilities:<rpc:<type:CREATE_DELETE_SNAPSHOT > > capabilities:<rpc:<type:LIST_SNAPSHOTS > > 
I1001 18:06:57.034] I1001 18:06:57.021949    8886 utils.go:112] GRPC call: /csi.v1.Node/NodeGetCapabilities
I1001 18:06:57.034] I1001 18:06:57.021983    8886 utils.go:113] GRPC request: 
I1001 18:06:57.035] I1001 18:06:57.021992    8886 nodeserver.go:272] Using default NodeGetCapabilities
I1001 18:06:57.035] I1001 18:06:57.021998    8886 utils.go:119] GRPC response: capabilities:<rpc:<type:STAGE_UNSTAGE_VOLUME > > 
I1001 18:06:57.035] I1001 18:06:57.022366    8886 utils.go:112] GRPC call: /csi.v1.Node/NodeUnpublishVolume
I1001 18:06:57.035] I1001 18:06:57.022390    8886 utils.go:113] GRPC request: 
I1001 18:06:57.035] E1001 18:06:57.022398    8886 utils.go:117] GRPC error: rpc error: code = InvalidArgument desc = Volume ID missing in request
I1001 18:06:57.036] •
I1001 18:06:57.036] ------------------------------
I1001 18:06:57.036] Node Service NodeUnpublishVolume 
I1001 18:06:57.036]   should fail when no target path is provided
I1001 18:06:57.036]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:217
I1001 18:06:57.037] STEP: reusing connection to CSI driver at unix:///tmp/csi.sock
I1001 18:06:57.037] STEP: creating mount and staging directories
I1001 18:06:57.037] I1001 18:06:57.022796    8886 utils.go:112] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1001 18:06:57.037] I1001 18:06:57.022816    8886 utils.go:113] GRPC request: 
I1001 18:06:57.037] I1001 18:06:57.022821    8886 controllerserver.go:415] Using default ControllerGetCapabilities
I1001 18:06:57.038] I1001 18:06:57.022825    8886 utils.go:119] GRPC response: capabilities:<rpc:<type:CREATE_DELETE_VOLUME > > capabilities:<rpc:<type:PUBLISH_UNPUBLISH_VOLUME > > capabilities:<rpc:<type:CREATE_DELETE_SNAPSHOT > > capabilities:<rpc:<type:LIST_SNAPSHOTS > > 
I1001 18:06:57.038] I1001 18:06:57.023281    8886 utils.go:112] GRPC call: /csi.v1.Node/NodeGetCapabilities
I1001 18:06:57.038] I1001 18:06:57.023308    8886 utils.go:113] GRPC request: 
I1001 18:06:57.038] I1001 18:06:57.023316    8886 nodeserver.go:272] Using default NodeGetCapabilities
I1001 18:06:57.038] I1001 18:06:57.023322    8886 utils.go:119] GRPC response: capabilities:<rpc:<type:STAGE_UNSTAGE_VOLUME > > 
I1001 18:06:57.039] I1001 18:06:57.023751    8886 utils.go:112] GRPC call: /csi.v1.Node/NodeUnpublishVolume
I1001 18:06:57.039] I1001 18:06:57.023773    8886 utils.go:113] GRPC request: volume_id:"id" 
I1001 18:06:57.039] E1001 18:06:57.023786    8886 utils.go:117] GRPC error: rpc error: code = InvalidArgument desc = Target path missing in request
I1001 18:06:57.039] •
I1001 18:06:57.040] ------------------------------
I1001 18:06:57.040] Node Service NodeStageVolume 
I1001 18:06:57.040]   should fail when no volume id is provided
I1001 18:06:57.041]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:245
I1001 18:06:57.041] STEP: reusing connection to CSI driver at unix:///tmp/csi.sock
I1001 18:06:57.041] STEP: creating mount and staging directories
I1001 18:06:57.042] I1001 18:06:57.024240    8886 utils.go:112] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1001 18:06:57.042] I1001 18:06:57.024269    8886 utils.go:113] GRPC request: 
I1001 18:06:57.042] I1001 18:06:57.024277    8886 controllerserver.go:415] Using default ControllerGetCapabilities
... skipping 2 lines ...
I1001 18:06:57.043] I1001 18:06:57.024803    8886 utils.go:113] GRPC request: 
I1001 18:06:57.043] I1001 18:06:57.024810    8886 nodeserver.go:272] Using default NodeGetCapabilities
I1001 18:06:57.044] I1001 18:06:57.024815    8886 utils.go:119] GRPC response: capabilities:<rpc:<type:STAGE_UNSTAGE_VOLUME > > 
I1001 18:06:57.044] I1001 18:06:57.025326    8886 utils.go:112] GRPC call: /csi.v1.Node/NodeStageVolume
I1001 18:06:57.045] I1001 18:06:57.025356    8886 utils.go:113] GRPC request: publish_context:<key:"device" value:"/dev/mock" > staging_target_path:"/tmp/csi" volume_capability:<mount:<> access_mode:<mode:SINGLE_NODE_WRITER > > 
I1001 18:06:57.045] I1001 18:06:57.025370    8886 nodeserver.go:50] NodeStageVolume: called with args {VolumeId: PublishContext:map[device:/dev/mock] StagingTargetPath:/tmp/csi VolumeCapability:mount:<> access_mode:<mode:SINGLE_NODE_WRITER >  Secrets:map[] VolumeContext:map[] XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
I1001 18:06:57.045] E1001 18:06:57.025423    8886 utils.go:117] GRPC error: rpc error: code = InvalidArgument desc = Volume ID not provided
I1001 18:06:57.046] •
I1001 18:06:57.046] ------------------------------
I1001 18:06:57.046] Node Service NodeStageVolume 
I1001 18:06:57.046]   should fail when no staging target path is provided
I1001 18:06:57.047]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:271
I1001 18:06:57.047] STEP: reusing connection to CSI driver at unix:///tmp/csi.sock
I1001 18:06:57.047] STEP: creating mount and staging directories
I1001 18:06:57.048] I1001 18:06:57.025905    8886 utils.go:112] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1001 18:06:57.048] I1001 18:06:57.025951    8886 utils.go:113] GRPC request: 
I1001 18:06:57.048] I1001 18:06:57.025961    8886 controllerserver.go:415] Using default ControllerGetCapabilities
... skipping 2 lines ...
I1001 18:06:57.050] I1001 18:06:57.026491    8886 utils.go:113] GRPC request: 
I1001 18:06:57.050] I1001 18:06:57.026502    8886 nodeserver.go:272] Using default NodeGetCapabilities
I1001 18:06:57.050] I1001 18:06:57.026509    8886 utils.go:119] GRPC response: capabilities:<rpc:<type:STAGE_UNSTAGE_VOLUME > > 
I1001 18:06:57.051] I1001 18:06:57.027028    8886 utils.go:112] GRPC call: /csi.v1.Node/NodeStageVolume
I1001 18:06:57.051] I1001 18:06:57.027057    8886 utils.go:113] GRPC request: volume_id:"id" publish_context:<key:"device" value:"/dev/mock" > volume_capability:<mount:<> access_mode:<mode:SINGLE_NODE_WRITER > > 
I1001 18:06:57.052] I1001 18:06:57.027070    8886 nodeserver.go:50] NodeStageVolume: called with args {VolumeId:id PublishContext:map[device:/dev/mock] StagingTargetPath: VolumeCapability:mount:<> access_mode:<mode:SINGLE_NODE_WRITER >  Secrets:map[] VolumeContext:map[] XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
I1001 18:06:57.052] E1001 18:06:57.027134    8886 utils.go:117] GRPC error: rpc error: code = InvalidArgument desc = Staging target not provided
I1001 18:06:57.053] •
I1001 18:06:57.053] ------------------------------
I1001 18:06:57.053] Node Service NodeStageVolume 
I1001 18:06:57.054]   should fail when no volume capability is provided
I1001 18:06:57.054]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:297
I1001 18:06:57.054] STEP: reusing connection to CSI driver at unix:///tmp/csi.sock
I1001 18:06:57.055] STEP: creating mount and staging directories
I1001 18:06:57.055] I1001 18:06:57.027606    8886 utils.go:112] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1001 18:06:57.055] I1001 18:06:57.027639    8886 utils.go:113] GRPC request: 
I1001 18:06:57.055] I1001 18:06:57.027648    8886 controllerserver.go:415] Using default ControllerGetCapabilities
... skipping 2 lines ...
I1001 18:06:57.056] I1001 18:06:57.028162    8886 utils.go:113] GRPC request: 
I1001 18:06:57.057] I1001 18:06:57.028169    8886 nodeserver.go:272] Using default NodeGetCapabilities
I1001 18:06:57.057] I1001 18:06:57.028176    8886 utils.go:119] GRPC response: capabilities:<rpc:<type:STAGE_UNSTAGE_VOLUME > > 
I1001 18:06:57.057] I1001 18:06:57.028687    8886 utils.go:112] GRPC call: /csi.v1.Node/NodeStageVolume
I1001 18:06:57.058] I1001 18:06:57.028752    8886 utils.go:113] GRPC request: volume_id:"id" publish_context:<key:"device" value:"/dev/mock" > staging_target_path:"/tmp/csi" 
I1001 18:06:57.058] I1001 18:06:57.028765    8886 nodeserver.go:50] NodeStageVolume: called with args {VolumeId:id PublishContext:map[device:/dev/mock] StagingTargetPath:/tmp/csi VolumeCapability:<nil> Secrets:map[] VolumeContext:map[] XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
I1001 18:06:57.058] E1001 18:06:57.028806    8886 utils.go:117] GRPC error: rpc error: code = InvalidArgument desc = Volume capability not provided
I1001 18:06:57.059] •
I1001 18:06:57.059] ------------------------------
I1001 18:06:57.059] Node Service NodeUnstageVolume 
I1001 18:06:57.059]   should fail when no volume id is provided
I1001 18:06:57.060]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:324
I1001 18:06:57.060] STEP: reusing connection to CSI driver at unix:///tmp/csi.sock
I1001 18:06:57.060] STEP: creating mount and staging directories
I1001 18:06:57.061] I1001 18:06:57.029314    8886 utils.go:112] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1001 18:06:57.061] I1001 18:06:57.029340    8886 utils.go:113] GRPC request: 
I1001 18:06:57.061] I1001 18:06:57.029348    8886 controllerserver.go:415] Using default ControllerGetCapabilities
... skipping 2 lines ...
I1001 18:06:57.062] I1001 18:06:57.029834    8886 utils.go:113] GRPC request: 
I1001 18:06:57.062] I1001 18:06:57.029841    8886 nodeserver.go:272] Using default NodeGetCapabilities
I1001 18:06:57.063] I1001 18:06:57.029847    8886 utils.go:119] GRPC response: capabilities:<rpc:<type:STAGE_UNSTAGE_VOLUME > > 
I1001 18:06:57.063] I1001 18:06:57.030303    8886 utils.go:112] GRPC call: /csi.v1.Node/NodeUnstageVolume
I1001 18:06:57.064] I1001 18:06:57.030334    8886 utils.go:113] GRPC request: staging_target_path:"/tmp/csi" 
I1001 18:06:57.064] I1001 18:06:57.030343    8886 nodeserver.go:146] NodeUnstageVolume: called with args {VolumeId: StagingTargetPath:/tmp/csi XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
I1001 18:06:57.064] E1001 18:06:57.030361    8886 utils.go:117] GRPC error: rpc error: code = InvalidArgument desc = Volume ID not provided
I1001 18:06:57.064] •
I1001 18:06:57.065] ------------------------------
I1001 18:06:57.065] Node Service NodeUnstageVolume 
I1001 18:06:57.065]   should fail when no staging target path is provided
I1001 18:06:57.065]   /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/node.go:338
I1001 18:06:57.066] STEP: reusing connection to CSI driver at unix:///tmp/csi.sock
I1001 18:06:57.066] STEP: creating mount and staging directories
I1001 18:06:57.066] I1001 18:06:57.030778    8886 utils.go:112] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1001 18:06:57.066] I1001 18:06:57.030797    8886 utils.go:113] GRPC request: 
I1001 18:06:57.067] I1001 18:06:57.030802    8886 controllerserver.go:415] Using default ControllerGetCapabilities
... skipping 2 lines ...
I1001 18:06:57.068] I1001 18:06:57.031212    8886 utils.go:113] GRPC request: 
I1001 18:06:57.068] I1001 18:06:57.031220    8886 nodeserver.go:272] Using default NodeGetCapabilities
I1001 18:06:57.068] I1001 18:06:57.031228    8886 utils.go:119] GRPC response: capabilities:<rpc:<type:STAGE_UNSTAGE_VOLUME > > 
I1001 18:06:57.069] I1001 18:06:57.031725    8886 utils.go:112] GRPC call: /csi.v1.Node/NodeUnstageVolume
I1001 18:06:57.069] I1001 18:06:57.031760    8886 utils.go:113] GRPC request: volume_id:"id" 
I1001 18:06:57.069] I1001 18:06:57.031778    8886 nodeserver.go:146] NodeUnstageVolume: called with args {VolumeId:id StagingTargetPath: XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
I1001 18:06:57.070] E1001 18:06:57.031816    8886 utils.go:117] GRPC error: rpc error: code = InvalidArgument desc = Staging target not provided
I1001 18:06:57.070] •S
I1001 18:06:57.070] 
I1001 18:06:57.070] Summarizing 2 Failures:
I1001 18:06:57.070] 
I1001 18:06:57.071] [Fail] Controller Service ControllerPublishVolume [It] should return appropriate values (no optional values added) 
I1001 18:06:57.071] /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:826
I1001 18:06:57.071] 
I1001 18:06:57.071] [Fail] Controller Service ControllerUnpublishVolume [It] should return appropriate values (no optional values added) 
I1001 18:06:57.072] /go/src/github.com/kubernetes-sigs/azuredisk-csi-driver/vendor/github.com/kubernetes-csi/csi-test/pkg/sanity/controller.go:1139
I1001 18:06:57.072] 
I1001 18:06:57.072] Ran 53 of 57 Specs in 373.405 seconds
I1001 18:06:57.072] FAIL! -- 51 Passed | 2 Failed | 0 Pending | 4 Skipped
I1001 18:06:57.073] --- FAIL: TestSanity (373.41s)
I1001 18:06:57.073] FAIL
I1001 18:06:57.073] pkill -f azurediskplugin
I1001 18:06:57.073] Deleting CSI sanity test binary
I1001 18:06:57.082] test/sanity/run-test.sh: line 19:  8886 Terminated              _output/azurediskplugin --endpoint "$endpoint" --nodeid "$nodeid" -v=5
I1001 18:06:57.083] 2019/10/01 18:06:57 Deleting resource group azuredisk-csi-driver-test-517a08e9-e475-11e9-9808-0a4a45922cfc
I1001 18:08:59.820] --- FAIL: TestSanity (525.74s)
I1001 18:08:59.821]     sanity_test.go:78: Sanity test failed exit status 1
I1001 18:08:59.821] FAIL
I1001 18:08:59.822] FAIL	github.com/kubernetes-sigs/azuredisk-csi-driver/test/sanity	525.758s
I1001 18:08:59.863] Makefile:51: recipe for target 'sanity-test' failed
W1001 18:08:59.868] make: *** [sanity-test] Error 1
W1001 18:08:59.868] Traceback (most recent call last):
W1001 18:08:59.868]   File "/workspace/./test-infra/jenkins/../scenarios/execute.py", line 50, in <module>
W1001 18:08:59.868]     main(ARGS.env, ARGS.cmd + ARGS.args)
W1001 18:08:59.868]   File "/workspace/./test-infra/jenkins/../scenarios/execute.py", line 41, in main
W1001 18:08:59.869]     check(*cmd)
W1001 18:08:59.869]   File "/workspace/./test-infra/jenkins/../scenarios/execute.py", line 30, in check
W1001 18:08:59.869]     subprocess.check_call(cmd)
W1001 18:08:59.869]   File "/usr/lib/python2.7/subprocess.py", line 186, in check_call
W1001 18:08:59.869]     raise CalledProcessError(retcode, cmd)
W1001 18:08:59.870] subprocess.CalledProcessError: Command '('make', 'sanity-test')' returned non-zero exit status 2
E1001 18:08:59.870] Command failed
I1001 18:08:59.870] process 456 exited with code 1 after 11.2m
E1001 18:08:59.870] FAIL: pull-azuredisk-csi-driver-sanity
I1001 18:08:59.870] Call:  gcloud auth activate-service-account --key-file=/etc/service-account/service-account.json
W1001 18:09:01.449] Activated service account credentials for: [kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com]
I1001 18:09:01.487] process 8919 exited with code 0 after 0.0m
I1001 18:09:01.487] Call:  gcloud config get-value account
I1001 18:09:01.736] process 8931 exited with code 0 after 0.0m
I1001 18:09:01.737] Will upload results to gs://kubernetes-upstream/pr-logs using kubernetes-upstream@kubernetes-upstream.iam.gserviceaccount.com
... skipping 28 lines ...
Result	FAILURE
Tests	0 failed / 0 succeeded
Started	2019-10-01 17:57
Elapsed	11m36s
Revision
Builder	dedd5914-e474-11e9-918b-16773c0c7aed
Refs	master:6b4d4209 166:35f2901a
infra-commit	edcabf6dd
repo	github.com/kubernetes-sigs/azuredisk-csi-driver
repo-commit	9a06ade8e6e1381f88f4332ea800e16364a342d0
repos	{u'github.com/kubernetes-sigs/azuredisk-csi-driver': u'master:6b4d4209385f8a3b04a39f1970017a27f2667a9a,166:35f2901acb3478c935a8b603cb4856fe60190383'}
kubernetes-sigs/azuredisk-csi-driver PR #166 pull-azuredisk-csi-driver-sanity #1179092917625556994

No Test Failures!

Error lines from build-log.txt
