I0207 04:00:28.258025       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0207 04:00:28.258138       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0207 04:00:28.258181       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0207 04:00:28.258186       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0207 04:00:28.258188       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0207 04:00:28.258191       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0207 04:00:28.258195       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0207 04:00:28.258198       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0207 04:00:28.258201       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0207 04:00:28.258204       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0207 04:00:28.258526       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0207 04:00:28.258611       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0207 04:00:32.411174       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0207 04:00:32.418550       1 utils.go:199] ID: 1 GRPC request: {}
I0207 04:00:32.418609       1 utils.go:205] ID: 1 GRPC response: {}
I0207 04:00:32.420168       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0207 04:00:32.420236       1 utils.go:199] ID: 2 GRPC request: {}
I0207 04:00:32.420251       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0207 04:00:32.420284       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0207 04:00:32.421170       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0207 04:00:32.421184       1 utils.go:199] ID: 3 GRPC request: {}
I0207 04:00:32.421194       1 utils.go:205] ID: 3 GRPC response: {}
I0207 04:00:32.421441       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0207 04:00:32.421475       1 utils.go:199] ID: 4 GRPC request: {}
I0207 04:00:32.421706       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0207 04:00:32.422386       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0207 04:00:32.422415       1 utils.go:199] ID: 5 GRPC request: {}
I0207 04:00:32.422421       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0207 04:00:32.422510       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}}}]}
I0207 04:00:34.362147       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0207 04:00:34.362260       1 utils.go:199] ID: 6 GRPC request: {}
I0207 04:00:34.362330       1 utils.go:205] ID: 6 GRPC response: {}
I0207 04:00:34.363841       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0207 04:00:34.363905       1 utils.go:199] ID: 7 GRPC request: {}
I0207 04:00:34.363912       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0207 04:00:34.363934       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0207 04:00:34.365430       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0207 04:00:34.365443       1 utils.go:199] ID: 8 GRPC request: {}
I0207 04:00:34.365461       1 utils.go:205] ID: 8 GRPC response: {}
I0207 04:00:34.365821       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0207 04:00:34.365832       1 utils.go:199] ID: 9 GRPC request: {}
I0207 04:00:34.365912       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0207 04:00:34.367581       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0207 04:00:34.367596       1 utils.go:199] ID: 10 GRPC request: {}
I0207 04:00:34.367602       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0207 04:00:34.367646       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}}}]}
I0207 04:00:34.368066       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0207 04:00:34.368077       1 utils.go:199] ID: 11 GRPC request: {}
I0207 04:00:34.368080       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0207 04:00:34.368122       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}}}]}
I0207 04:00:34.368385       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0207 04:00:34.368395       1 utils.go:199] ID: 12 GRPC request: {}
I0207 04:00:34.368399       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0207 04:00:34.368442       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}}}]}
I0207 04:00:36.499939       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0207 04:00:36.499972       1 utils.go:199] ID: 13 GRPC request: {}
I0207 04:00:36.499978       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0207 04:00:36.500075       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0207 04:00:36.503368       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0207 04:00:36.503384       1 utils.go:199] ID: 14 GRPC request: {}
I0207 04:00:36.503450       1 utils.go:205] ID: 14 GRPC response: {}
I0207 04:00:36.508895       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0207 04:00:36.508911       1 utils.go:199] ID: 15 GRPC request: {}
I0207 04:00:36.508917       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0207 04:00:36.509030       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}}}]}
I0207 04:00:38.510103       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0207 04:00:38.510140       1 utils.go:199] ID: 16 GRPC request: {}
I0207 04:00:38.510161       1 utils.go:205] ID: 16 GRPC response: {}
I0207 04:00:38.516088       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0207 04:00:38.516104       1 utils.go:199] ID: 17 GRPC request: {}
I0207 04:00:38.516111       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0207 04:00:38.516243       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0207 04:00:38.517646       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0207 04:00:38.517663       1 utils.go:199] ID: 18 GRPC request: {}
I0207 04:00:38.517671       1 utils.go:205] ID: 18 GRPC response: {}
I0207 04:00:38.518069       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0207 04:00:38.518084       1 utils.go:199] ID: 19 GRPC request: {}
I0207 04:00:38.518232       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0207 04:00:38.519201       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0207 04:00:38.519342       1 utils.go:199] ID: 20 GRPC request: {}
I0207 04:00:38.519382       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0207 04:00:38.519504       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}}}]}
I0207 04:01:38.726677       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0207 04:01:38.727013       1 utils.go:199] ID: 21 GRPC request: {}
I0207 04:01:38.727917       1 utils.go:205] ID: 21 GRPC response: {}
I0207 04:02:38.730336       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0207 04:02:38.730862       1 utils.go:199] ID: 22 GRPC request: {}
I0207 04:02:38.731038       1 utils.go:205] ID: 22 GRPC response: {}
I0207 04:03:35.230253       1 utils.go:198] ID: 23 Req-ID: pvc-fc4e752d-75e0-4ea6-a5c7-a323f96a2751 GRPC call: /csi.v1.Controller/CreateVolume
I0207 04:03:35.230759       1 utils.go:199] ID: 23 Req-ID: pvc-fc4e752d-75e0-4ea6-a5c7-a323f96a2751 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-fc4e752d-75e0-4ea6-a5c7-a323f96a2751","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-fc4e752d-75e0-4ea6-a5c7-a323f96a2751","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}}]}
I0207 04:03:35.231135       1 rbd_util.go:1315] ID: 23 Req-ID: pvc-fc4e752d-75e0-4ea6-a5c7-a323f96a2751 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0207 04:03:35.270846       1 omap.go:80] ID: 23 Req-ID: pvc-fc4e752d-75e0-4ea6-a5c7-a323f96a2751 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0207 04:03:35.287077       1 omap.go:159] ID: 23 Req-ID: pvc-fc4e752d-75e0-4ea6-a5c7-a323f96a2751 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-fc4e752d-75e0-4ea6-a5c7-a323f96a2751:aff612d4-3e8b-4a8d-9bea-a7d7968a8477])
I0207 04:03:35.292739       1 omap.go:159] ID: 23 Req-ID: pvc-fc4e752d-75e0-4ea6-a5c7-a323f96a2751 set omap keys (pool="kube", namespace="", name="csi.volume.aff612d4-3e8b-4a8d-9bea-a7d7968a8477"): map[csi.imagename:csi-vol-aff612d4-3e8b-4a8d-9bea-a7d7968a8477 csi.volname:pvc-fc4e752d-75e0-4ea6-a5c7-a323f96a2751 csi.volume.owner:default])
I0207 04:03:35.292765       1 rbd_journal.go:491] ID: 23 Req-ID: pvc-fc4e752d-75e0-4ea6-a5c7-a323f96a2751 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-aff612d4-3e8b-4a8d-9bea-a7d7968a8477) and image name (csi-vol-aff612d4-3e8b-4a8d-9bea-a7d7968a8477) for request name (pvc-fc4e752d-75e0-4ea6-a5c7-a323f96a2751)
I0207 04:03:35.292839       1 rbd_util.go:423] ID: 23 Req-ID: pvc-fc4e752d-75e0-4ea6-a5c7-a323f96a2751 rbd: create kube/csi-vol-aff612d4-3e8b-4a8d-9bea-a7d7968a8477 size 5120M (features: [layering]) using mon 199.204.45.67
I0207 04:03:35.292882       1 rbd_util.go:1563] ID: 23 Req-ID: pvc-fc4e752d-75e0-4ea6-a5c7-a323f96a2751 setting image options on kube/csi-vol-aff612d4-3e8b-4a8d-9bea-a7d7968a8477
I0207 04:03:36.643501       1 controllerserver.go:763] ID: 23 Req-ID: pvc-fc4e752d-75e0-4ea6-a5c7-a323f96a2751 created image kube/csi-vol-aff612d4-3e8b-4a8d-9bea-a7d7968a8477 backed for request name pvc-fc4e752d-75e0-4ea6-a5c7-a323f96a2751
I0207 04:03:36.692437       1 omap.go:159] ID: 23 Req-ID: pvc-fc4e752d-75e0-4ea6-a5c7-a323f96a2751 set omap keys (pool="kube", namespace="", name="csi.volume.aff612d4-3e8b-4a8d-9bea-a7d7968a8477"): map[csi.imageid:37d997ca175f])
I0207 04:03:36.774348       1 utils.go:205] ID: 23 Req-ID: pvc-fc4e752d-75e0-4ea6-a5c7-a323f96a2751 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-aff612d4-3e8b-4a8d-9bea-a7d7968a8477","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-aff612d4-3e8b-4a8d-9bea-a7d7968a8477"}}
I0207 04:03:38.784633       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0207 04:03:38.784691       1 utils.go:199] ID: 24 GRPC request: {}
I0207 04:03:38.784713       1 utils.go:205] ID: 24 GRPC response: {}