I0225 19:34:22.818528       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0225 19:34:22.818678       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0225 19:34:22.818690       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0225 19:34:22.818698       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0225 19:34:22.818701       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0225 19:34:22.818703       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0225 19:34:22.818709       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0225 19:34:22.818712       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0225 19:34:22.818715       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0225 19:34:22.818718       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0225 19:34:22.818964       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0225 19:34:22.818991       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0225 19:34:25.785498       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0225 19:34:25.786611       1 utils.go:199] ID: 1 GRPC request: {}
I0225 19:34:25.786709       1 utils.go:205] ID: 1 GRPC response: {}
I0225 19:34:25.789348       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0225 19:34:25.789596       1 utils.go:199] ID: 2 GRPC request: {}
I0225 19:34:25.789626       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0225 19:34:25.789763       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0225 19:34:25.795141       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0225 19:34:25.795183       1 utils.go:199] ID: 3 GRPC request: {}
I0225 19:34:25.795212       1 utils.go:205] ID: 3 GRPC response: {}
I0225 19:34:25.795728       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0225 19:34:25.795854       1 utils.go:199] ID: 4 GRPC request: {}
I0225 19:34:25.796146       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0225 19:34:25.796988       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0225 19:34:25.797070       1 utils.go:199] ID: 5 GRPC request: {}
I0225 19:34:25.797086       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0225 19:34:25.797276       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}}}]}
I0225 19:34:38.512166       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0225 19:34:38.512213       1 utils.go:199] ID: 6 GRPC request: {}
I0225 19:34:38.512239       1 utils.go:205] ID: 6 GRPC response: {}
I0225 19:34:38.515245       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0225 19:34:38.515282       1 utils.go:199] ID: 7 GRPC request: {}
I0225 19:34:38.515291       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0225 19:34:38.515319       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0225 19:34:38.517010       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0225 19:34:38.517034       1 utils.go:199] ID: 8 GRPC request: {}
I0225 19:34:38.517056       1 utils.go:205] ID: 8 GRPC response: {}
I0225 19:34:38.517525       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0225 19:34:38.517549       1 utils.go:199] ID: 9 GRPC request: {}
I0225 19:34:38.517672       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0225 19:34:38.518397       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0225 19:34:38.518431       1 utils.go:199] ID: 10 GRPC request: {}
I0225 19:34:38.518449       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0225 19:34:38.518536       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}}}]}
I0225 19:34:38.519040       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0225 19:34:38.519057       1 utils.go:199] ID: 11 GRPC request: {}
I0225 19:34:38.519062       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0225 19:34:38.519132       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}}}]}
I0225 19:34:38.519446       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0225 19:34:38.519466       1 utils.go:199] ID: 12 GRPC request: {}
I0225 19:34:38.519480       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0225 19:34:38.519537       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}}}]}
I0225 19:34:40.766445       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0225 19:34:40.766475       1 utils.go:199] ID: 13 GRPC request: {}
I0225 19:34:40.766482       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0225 19:34:40.766501       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0225 19:34:40.769451       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0225 19:34:40.769481       1 utils.go:199] ID: 14 GRPC request: {}
I0225 19:34:40.769704       1 utils.go:205] ID: 14 GRPC response: {}
I0225 19:34:40.771225       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0225 19:34:40.771269       1 utils.go:199] ID: 15 GRPC request: {}
I0225 19:34:40.771280       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0225 19:34:40.771417       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}}}]}
I0225 19:34:42.548880       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0225 19:34:42.548923       1 utils.go:199] ID: 16 GRPC request: {}
I0225 19:34:42.548943       1 utils.go:205] ID: 16 GRPC response: {}
I0225 19:34:42.552607       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0225 19:34:42.552627       1 utils.go:199] ID: 17 GRPC request: {}
I0225 19:34:42.552635       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0225 19:34:42.552684       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0225 19:34:42.554426       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0225 19:34:42.554444       1 utils.go:199] ID: 18 GRPC request: {}
I0225 19:34:42.554454       1 utils.go:205] ID: 18 GRPC response: {}
I0225 19:34:42.554735       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0225 19:34:42.554751       1 utils.go:199] ID: 19 GRPC request: {}
I0225 19:34:42.554907       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0225 19:34:42.555676       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0225 19:34:42.555722       1 utils.go:199] ID: 20 GRPC request: {}
I0225 19:34:42.555733       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0225 19:34:42.555829       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}}}]}
I0225 19:35:43.197208       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0225 19:35:43.197250       1 utils.go:199] ID: 21 GRPC request: {}
I0225 19:35:43.197269       1 utils.go:205] ID: 21 GRPC response: {}
I0225 19:36:43.204685       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0225 19:36:43.204788       1 utils.go:199] ID: 22 GRPC request: {}
I0225 19:36:43.204863       1 utils.go:205] ID: 22 GRPC response: {}
I0225 19:37:30.963522       1 utils.go:198] ID: 23 Req-ID: pvc-3a08511e-490d-4485-b1c6-5a050bc3f4d4 GRPC call: /csi.v1.Controller/CreateVolume
I0225 19:37:30.963816       1 utils.go:199] ID: 23 Req-ID: pvc-3a08511e-490d-4485-b1c6-5a050bc3f4d4 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-3a08511e-490d-4485-b1c6-5a050bc3f4d4","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-3a08511e-490d-4485-b1c6-5a050bc3f4d4","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}}]}
I0225 19:37:30.963995       1 rbd_util.go:1315] ID: 23 Req-ID: pvc-3a08511e-490d-4485-b1c6-5a050bc3f4d4 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0225 19:37:30.982456       1 omap.go:80] ID: 23 Req-ID: pvc-3a08511e-490d-4485-b1c6-5a050bc3f4d4 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0225 19:37:30.998604       1 omap.go:159] ID: 23 Req-ID: pvc-3a08511e-490d-4485-b1c6-5a050bc3f4d4 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-3a08511e-490d-4485-b1c6-5a050bc3f4d4:0f2fee57-9605-40bd-bd75-8b30b8fa39b6])
I0225 19:37:31.007962       1 omap.go:159] ID: 23 Req-ID: pvc-3a08511e-490d-4485-b1c6-5a050bc3f4d4 set omap keys (pool="kube", namespace="", name="csi.volume.0f2fee57-9605-40bd-bd75-8b30b8fa39b6"): map[csi.imagename:csi-vol-0f2fee57-9605-40bd-bd75-8b30b8fa39b6 csi.volname:pvc-3a08511e-490d-4485-b1c6-5a050bc3f4d4 csi.volume.owner:default])
I0225 19:37:31.008040       1 rbd_journal.go:491] ID: 23 Req-ID: pvc-3a08511e-490d-4485-b1c6-5a050bc3f4d4 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-0f2fee57-9605-40bd-bd75-8b30b8fa39b6) and image name (csi-vol-0f2fee57-9605-40bd-bd75-8b30b8fa39b6) for request name (pvc-3a08511e-490d-4485-b1c6-5a050bc3f4d4)
I0225 19:37:31.008219       1 rbd_util.go:423] ID: 23 Req-ID: pvc-3a08511e-490d-4485-b1c6-5a050bc3f4d4 rbd: create kube/csi-vol-0f2fee57-9605-40bd-bd75-8b30b8fa39b6 size 5120M (features: [layering]) using mon 199.19.213.246
I0225 19:37:31.008365       1 rbd_util.go:1563] ID: 23 Req-ID: pvc-3a08511e-490d-4485-b1c6-5a050bc3f4d4 setting image options on kube/csi-vol-0f2fee57-9605-40bd-bd75-8b30b8fa39b6
I0225 19:37:32.893699       1 controllerserver.go:763] ID: 23 Req-ID: pvc-3a08511e-490d-4485-b1c6-5a050bc3f4d4 created image kube/csi-vol-0f2fee57-9605-40bd-bd75-8b30b8fa39b6 backed for request name pvc-3a08511e-490d-4485-b1c6-5a050bc3f4d4
I0225 19:37:32.930160       1 omap.go:159] ID: 23 Req-ID: pvc-3a08511e-490d-4485-b1c6-5a050bc3f4d4 set omap keys (pool="kube", namespace="", name="csi.volume.0f2fee57-9605-40bd-bd75-8b30b8fa39b6"): map[csi.imageid:37d7124d9798])
I0225 19:37:33.038215       1 utils.go:205] ID: 23 Req-ID: pvc-3a08511e-490d-4485-b1c6-5a050bc3f4d4 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-0f2fee57-9605-40bd-bd75-8b30b8fa39b6","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-0f2fee57-9605-40bd-bd75-8b30b8fa39b6"}}
I0225 19:37:43.197091       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0225 19:37:43.197161       1 utils.go:199] ID: 24 GRPC request: {}
I0225 19:37:43.197185       1 utils.go:205] ID: 24 GRPC response: {}