I0726 17:05:47.656282       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0726 17:05:47.656434       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0726 17:05:47.656450       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0726 17:05:47.656455       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0726 17:05:47.656460       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0726 17:05:47.656464       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0726 17:05:47.656470       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0726 17:05:47.656474       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0726 17:05:47.656478       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0726 17:05:47.656483       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0726 17:05:47.656831       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0726 17:05:47.656839       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0726 17:05:49.542689       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0726 17:05:49.543725       1 utils.go:199] ID: 1 GRPC request: {}
I0726 17:05:49.543770       1 utils.go:205] ID: 1 GRPC response: {}
I0726 17:05:49.545559       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0726 17:05:49.545590       1 utils.go:199] ID: 2 GRPC request: {}
I0726 17:05:49.545600       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0726 17:05:49.545642       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0726 17:05:49.547381       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0726 17:05:49.547445       1 utils.go:199] ID: 3 GRPC request: {}
I0726 17:05:49.547508       1 utils.go:205] ID: 3 GRPC response: {}
I0726 17:05:49.548221       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0726 17:05:49.548328       1 utils.go:199] ID: 4 GRPC request: {}
I0726 17:05:49.548548       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0726 17:05:49.549482       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0726 17:05:49.549521       1 utils.go:199] ID: 5 GRPC request: {}
I0726 17:05:49.549532       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0726 17:05:49.549642       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}}}]}
I0726 17:05:50.764256       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0726 17:05:50.764312       1 utils.go:199] ID: 6 GRPC request: {}
I0726 17:05:50.764341       1 utils.go:205] ID: 6 GRPC response: {}
I0726 17:05:50.770376       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0726 17:05:50.770506       1 utils.go:199] ID: 7 GRPC request: {}
I0726 17:05:50.770533       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0726 17:05:50.770612       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0726 17:05:50.773085       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0726 17:05:50.773107       1 utils.go:199] ID: 8 GRPC request: {}
I0726 17:05:50.773120       1 utils.go:205] ID: 8 GRPC response: {}
I0726 17:05:50.773739       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0726 17:05:50.773757       1 utils.go:199] ID: 9 GRPC request: {}
I0726 17:05:50.773937       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0726 17:05:50.775065       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0726 17:05:50.775186       1 utils.go:199] ID: 10 GRPC request: {}
I0726 17:05:50.775259       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0726 17:05:50.775450       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}}}]}
I0726 17:05:50.776371       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0726 17:05:50.776392       1 utils.go:199] ID: 11 GRPC request: {}
I0726 17:05:50.776399       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0726 17:05:50.776591       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}}}]}
I0726 17:05:50.777295       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0726 17:05:50.777388       1 utils.go:199] ID: 12 GRPC request: {}
I0726 17:05:50.777422       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0726 17:05:50.777628       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}}}]}
I0726 17:05:52.002135       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0726 17:05:52.002194       1 utils.go:199] ID: 13 GRPC request: {}
I0726 17:05:52.002214       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0726 17:05:52.002267       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0726 17:05:52.005931       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0726 17:05:52.005957       1 utils.go:199] ID: 14 GRPC request: {}
I0726 17:05:52.005976       1 utils.go:205] ID: 14 GRPC response: {}
I0726 17:05:52.006825       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0726 17:05:52.006886       1 utils.go:199] ID: 15 GRPC request: {}
I0726 17:05:52.006898       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0726 17:05:52.007027       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}}}]}
I0726 17:05:53.221341       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0726 17:05:53.221408       1 utils.go:199] ID: 16 GRPC request: {}
I0726 17:05:53.221437       1 utils.go:205] ID: 16 GRPC response: {}
I0726 17:05:53.224038       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0726 17:05:53.224127       1 utils.go:199] ID: 17 GRPC request: {}
I0726 17:05:53.224158       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0726 17:05:53.224239       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0726 17:05:53.227187       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0726 17:05:53.227238       1 utils.go:199] ID: 18 GRPC request: {}
I0726 17:05:53.227255       1 utils.go:205] ID: 18 GRPC response: {}
I0726 17:05:53.227656       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0726 17:05:53.227716       1 utils.go:199] ID: 19 GRPC request: {}
I0726 17:05:53.227948       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0726 17:05:53.228541       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0726 17:05:53.228559       1 utils.go:199] ID: 20 GRPC request: {}
I0726 17:05:53.228567       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0726 17:05:53.228648       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}}}]}
I0726 17:06:53.470664       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0726 17:06:53.470698       1 utils.go:199] ID: 21 GRPC request: {}
I0726 17:06:53.470711       1 utils.go:205] ID: 21 GRPC response: {}
I0726 17:07:53.419616       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0726 17:07:53.419721       1 utils.go:199] ID: 22 GRPC request: {}
I0726 17:07:53.419772       1 utils.go:205] ID: 22 GRPC response: {}
I0726 17:08:53.413989       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0726 17:08:53.414086       1 utils.go:199] ID: 23 GRPC request: {}
I0726 17:08:53.414134       1 utils.go:205] ID: 23 GRPC response: {}
I0726 17:09:53.424944       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0726 17:09:53.425058       1 utils.go:199] ID: 24 GRPC request: {}
I0726 17:09:53.425113       1 utils.go:205] ID: 24 GRPC response: {}
I0726 17:10:53.413714       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0726 17:10:53.413879       1 utils.go:199] ID: 25 GRPC request: {}
I0726 17:10:53.413967       1 utils.go:205] ID: 25 GRPC response: {}
I0726 17:11:20.001763       1 utils.go:198] ID: 26 Req-ID: pvc-0e5eb4ff-e784-40b0-bd4e-5e23e82cd3e4 GRPC call: /csi.v1.Controller/CreateVolume
I0726 17:11:20.002564       1 utils.go:199] ID: 26 Req-ID: pvc-0e5eb4ff-e784-40b0-bd4e-5e23e82cd3e4 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-0e5eb4ff-e784-40b0-bd4e-5e23e82cd3e4","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-0e5eb4ff-e784-40b0-bd4e-5e23e82cd3e4","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}}]}
I0726 17:11:20.002836       1 rbd_util.go:1315] ID: 26 Req-ID: pvc-0e5eb4ff-e784-40b0-bd4e-5e23e82cd3e4 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0726 17:11:20.022022       1 omap.go:80] ID: 26 Req-ID: pvc-0e5eb4ff-e784-40b0-bd4e-5e23e82cd3e4 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0726 17:11:20.039800       1 omap.go:159] ID: 26 Req-ID: pvc-0e5eb4ff-e784-40b0-bd4e-5e23e82cd3e4 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-0e5eb4ff-e784-40b0-bd4e-5e23e82cd3e4:68c48bf4-f081-496d-aa0a-61992350f04a])
I0726 17:11:20.046194       1 omap.go:159] ID: 26 Req-ID: pvc-0e5eb4ff-e784-40b0-bd4e-5e23e82cd3e4 set omap keys (pool="kube", namespace="", name="csi.volume.68c48bf4-f081-496d-aa0a-61992350f04a"): map[csi.imagename:csi-vol-68c48bf4-f081-496d-aa0a-61992350f04a csi.volname:pvc-0e5eb4ff-e784-40b0-bd4e-5e23e82cd3e4 csi.volume.owner:default])
I0726 17:11:20.046234       1 rbd_journal.go:491] ID: 26 Req-ID: pvc-0e5eb4ff-e784-40b0-bd4e-5e23e82cd3e4 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-68c48bf4-f081-496d-aa0a-61992350f04a) and image name (csi-vol-68c48bf4-f081-496d-aa0a-61992350f04a) for request name (pvc-0e5eb4ff-e784-40b0-bd4e-5e23e82cd3e4)
I0726 17:11:20.046305       1 rbd_util.go:423] ID: 26 Req-ID: pvc-0e5eb4ff-e784-40b0-bd4e-5e23e82cd3e4 rbd: create kube/csi-vol-68c48bf4-f081-496d-aa0a-61992350f04a size 5120M (features: [layering]) using mon 199.204.45.57
I0726 17:11:20.046339       1 rbd_util.go:1563] ID: 26 Req-ID: pvc-0e5eb4ff-e784-40b0-bd4e-5e23e82cd3e4 setting image options on kube/csi-vol-68c48bf4-f081-496d-aa0a-61992350f04a
I0726 17:11:20.080524       1 controllerserver.go:763] ID: 26 Req-ID: pvc-0e5eb4ff-e784-40b0-bd4e-5e23e82cd3e4 created image kube/csi-vol-68c48bf4-f081-496d-aa0a-61992350f04a backed for request name pvc-0e5eb4ff-e784-40b0-bd4e-5e23e82cd3e4
I0726 17:11:20.118361       1 omap.go:159] ID: 26 Req-ID: pvc-0e5eb4ff-e784-40b0-bd4e-5e23e82cd3e4 set omap keys (pool="kube", namespace="", name="csi.volume.68c48bf4-f081-496d-aa0a-61992350f04a"): map[csi.imageid:37f4b847e393])
I0726 17:11:20.220576       1 utils.go:205] ID: 26 Req-ID: pvc-0e5eb4ff-e784-40b0-bd4e-5e23e82cd3e4 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-68c48bf4-f081-496d-aa0a-61992350f04a","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-68c48bf4-f081-496d-aa0a-61992350f04a"}}
I0726 17:11:53.442919       1 utils.go:198] ID: 27 GRPC call: /csi.v1.Identity/Probe
I0726 17:11:53.442989       1 utils.go:199] ID: 27 GRPC request: {}
I0726 17:11:53.443018       1 utils.go:205] ID: 27 GRPC response: {}