I0129 03:00:06.524824       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0129 03:00:06.525073       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0129 03:00:06.525374       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0129 03:00:06.525382       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0129 03:00:06.525385       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0129 03:00:06.525388       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0129 03:00:06.525392       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0129 03:00:06.525457       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0129 03:00:06.525461       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0129 03:00:06.525534       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0129 03:00:06.525926       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0129 03:00:06.525934       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0129 03:00:10.885220       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0129 03:00:10.888268       1 utils.go:199] ID: 1 GRPC request: {}
I0129 03:00:10.888364       1 utils.go:205] ID: 1 GRPC response: {}
I0129 03:00:10.894570       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0129 03:00:10.894720       1 utils.go:199] ID: 2 GRPC request: {}
I0129 03:00:10.894777       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0129 03:00:10.894853       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0129 03:00:10.895879       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0129 03:00:10.895899       1 utils.go:199] ID: 3 GRPC request: {}
I0129 03:00:10.895908       1 utils.go:205] ID: 3 GRPC response: {}
I0129 03:00:10.896154       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0129 03:00:10.896192       1 utils.go:199] ID: 4 GRPC request: {}
I0129 03:00:10.896294       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0129 03:00:10.896779       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0129 03:00:10.896813       1 utils.go:199] ID: 5 GRPC request: {}
I0129 03:00:10.896823       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0129 03:00:10.896926       1 utils.go:205] ID: 5 GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}}]}
I0129 03:00:16.254840       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0129 03:00:16.254945       1 utils.go:199] ID: 6 GRPC request: {}
I0129 03:00:16.255034       1 utils.go:205] ID: 6 GRPC response: {}
I0129 03:00:16.256909       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0129 03:00:16.256990       1 utils.go:199] ID: 7 GRPC request: {}
I0129 03:00:16.257045       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0129 03:00:16.257137       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0129 03:00:16.258339       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0129 03:00:16.258402       1 utils.go:199] ID: 8 GRPC request: {}
I0129 03:00:16.258463       1 utils.go:205] ID: 8 GRPC response: {}
I0129 03:00:16.258850       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0129 03:00:16.258935       1 utils.go:199] ID: 9 GRPC request: {}
I0129 03:00:16.259054       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0129 03:00:16.259654       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0129 03:00:16.259756       1 utils.go:199] ID: 10 GRPC request: {}
I0129 03:00:16.259834       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0129 03:00:16.259995       1 utils.go:205] ID: 10 GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}}]}
I0129 03:00:16.260551       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0129 03:00:16.260648       1 utils.go:199] ID: 11 GRPC request: {}
I0129 03:00:16.260721       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0129 03:00:16.260842       1 utils.go:205] ID: 11 GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}}]}
I0129 03:00:16.261204       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0129 03:00:16.261319       1 utils.go:199] ID: 12 GRPC request: {}
I0129 03:00:16.261416       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0129 03:00:16.261589       1 utils.go:205] ID: 12 GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}}]}
I0129 03:00:18.311344       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0129 03:00:18.311473       1 utils.go:199] ID: 13 GRPC request: {}
I0129 03:00:18.311536       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0129 03:00:18.311650       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0129 03:00:18.315202       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0129 03:00:18.315298       1 utils.go:199] ID: 14 GRPC request: {}
I0129 03:00:18.315353       1 utils.go:205] ID: 14 GRPC response: {}
I0129 03:00:18.315680       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0129 03:00:18.315753       1 utils.go:199] ID: 15 GRPC request: {}
I0129 03:00:18.315805       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0129 03:00:18.315941       1 utils.go:205] ID: 15 GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}}]}
I0129 03:00:21.082182       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0129 03:00:21.082232       1 utils.go:199] ID: 16 GRPC request: {}
I0129 03:00:21.082251       1 utils.go:205] ID: 16 GRPC response: {}
I0129 03:00:21.088353       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0129 03:00:21.088389       1 utils.go:199] ID: 17 GRPC request: {}
I0129 03:00:21.088396       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0129 03:00:21.088511       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0129 03:00:21.090896       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0129 03:00:21.090926       1 utils.go:199] ID: 18 GRPC request: {}
I0129 03:00:21.090939       1 utils.go:205] ID: 18 GRPC response: {}
I0129 03:00:21.091336       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0129 03:00:21.091355       1 utils.go:199] ID: 19 GRPC request: {}
I0129 03:00:21.091435       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0129 03:00:21.092158       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0129 03:00:21.092184       1 utils.go:199] ID: 20 GRPC request: {}
I0129 03:00:21.092190       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0129 03:00:21.092257       1 utils.go:205] ID: 20 GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}}]}
I0129 03:01:21.439831       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0129 03:01:21.440164       1 utils.go:199] ID: 21 GRPC request: {}
I0129 03:01:21.440369       1 utils.go:205] ID: 21 GRPC response: {}
I0129 03:02:21.400764       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0129 03:02:21.401146       1 utils.go:199] ID: 22 GRPC request: {}
I0129 03:02:21.406723       1 utils.go:205] ID: 22 GRPC response: {}
I0129 03:03:15.510900       1 utils.go:198] ID: 23 Req-ID: pvc-212972cc-cc2e-44ab-80a6-a7acc4155b17 GRPC call: /csi.v1.Controller/CreateVolume
I0129 03:03:15.511367       1 utils.go:199] ID: 23 Req-ID: pvc-212972cc-cc2e-44ab-80a6-a7acc4155b17 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-212972cc-cc2e-44ab-80a6-a7acc4155b17","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-212972cc-cc2e-44ab-80a6-a7acc4155b17","csi.storage.k8s.io/pvc/name":"test-pvc","csi.storage.k8s.io/pvc/namespace":"default","imageFeatures":"layering","pool":"kube"},"secrets":"***stripped***","volume_capabilities":[{"AccessType":{"Mount":{"fs_type":"ext4","mount_flags":["discard"]}},"access_mode":{"mode":1}}]}
I0129 03:03:15.514000       1 rbd_util.go:1315] ID: 23 Req-ID: pvc-212972cc-cc2e-44ab-80a6-a7acc4155b17 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0129 03:03:15.557666       1 omap.go:80] ID: 23 Req-ID: pvc-212972cc-cc2e-44ab-80a6-a7acc4155b17 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0129 03:03:15.574641       1 omap.go:159] ID: 23 Req-ID: pvc-212972cc-cc2e-44ab-80a6-a7acc4155b17 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-212972cc-cc2e-44ab-80a6-a7acc4155b17:4ef6c171-5976-4a6c-8b69-836aa09dd967])
I0129 03:03:15.580178       1 omap.go:159] ID: 23 Req-ID: pvc-212972cc-cc2e-44ab-80a6-a7acc4155b17 set omap keys (pool="kube", namespace="", name="csi.volume.4ef6c171-5976-4a6c-8b69-836aa09dd967"): map[csi.imagename:csi-vol-4ef6c171-5976-4a6c-8b69-836aa09dd967 csi.volname:pvc-212972cc-cc2e-44ab-80a6-a7acc4155b17 csi.volume.owner:default])
I0129 03:03:15.580201       1 rbd_journal.go:491] ID: 23 Req-ID: pvc-212972cc-cc2e-44ab-80a6-a7acc4155b17 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-4ef6c171-5976-4a6c-8b69-836aa09dd967) and image name (csi-vol-4ef6c171-5976-4a6c-8b69-836aa09dd967) for request name (pvc-212972cc-cc2e-44ab-80a6-a7acc4155b17)
I0129 03:03:15.580259       1 rbd_util.go:423] ID: 23 Req-ID: pvc-212972cc-cc2e-44ab-80a6-a7acc4155b17 rbd: create kube/csi-vol-4ef6c171-5976-4a6c-8b69-836aa09dd967 size 5120M (features: [layering]) using mon 199.204.45.113
I0129 03:03:15.580308       1 rbd_util.go:1563] ID: 23 Req-ID: pvc-212972cc-cc2e-44ab-80a6-a7acc4155b17 setting image options on kube/csi-vol-4ef6c171-5976-4a6c-8b69-836aa09dd967
I0129 03:03:17.617155       1 controllerserver.go:763] ID: 23 Req-ID: pvc-212972cc-cc2e-44ab-80a6-a7acc4155b17 created image kube/csi-vol-4ef6c171-5976-4a6c-8b69-836aa09dd967 backed for request name pvc-212972cc-cc2e-44ab-80a6-a7acc4155b17
I0129 03:03:17.649922       1 omap.go:159] ID: 23 Req-ID: pvc-212972cc-cc2e-44ab-80a6-a7acc4155b17 set omap keys (pool="kube", namespace="", name="csi.volume.4ef6c171-5976-4a6c-8b69-836aa09dd967"): map[csi.imageid:37d91126e03a])
I0129 03:03:17.729590       1 utils.go:205] ID: 23 Req-ID: pvc-212972cc-cc2e-44ab-80a6-a7acc4155b17 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-4ef6c171-5976-4a6c-8b69-836aa09dd967","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-4ef6c171-5976-4a6c-8b69-836aa09dd967"}}
I0129 03:03:21.382239       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0129 03:03:21.384093       1 utils.go:199] ID: 24 GRPC request: {}
I0129 03:03:21.384524       1 utils.go:205] ID: 24 GRPC response: {}