I0408 06:19:15.970697       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0408 06:19:15.970809       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0408 06:19:15.970821       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0408 06:19:15.970825       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0408 06:19:15.970827       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0408 06:19:15.970830       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0408 06:19:15.970835       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0408 06:19:15.970838       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0408 06:19:15.970840       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0408 06:19:15.970842       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0408 06:19:15.971143       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0408 06:19:15.971168       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0408 06:19:25.420856       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0408 06:19:25.422718       1 utils.go:199] ID: 1 GRPC request: {}
I0408 06:19:25.422777       1 utils.go:205] ID: 1 GRPC response: {}
I0408 06:19:25.424820       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0408 06:19:25.424917       1 utils.go:199] ID: 2 GRPC request: {}
I0408 06:19:25.424959       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0408 06:19:25.425030       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0408 06:19:25.426248       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0408 06:19:25.426312       1 utils.go:199] ID: 3 GRPC request: {}
I0408 06:19:25.426350       1 utils.go:205] ID: 3 GRPC response: {}
I0408 06:19:25.426788       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0408 06:19:25.426866       1 utils.go:199] ID: 4 GRPC request: {}
I0408 06:19:25.427079       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0408 06:19:25.428761       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0408 06:19:25.428914       1 utils.go:199] ID: 5 GRPC request: {}
I0408 06:19:25.428937       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0408 06:19:25.429248       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}}}]}
I0408 06:19:29.954167       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0408 06:19:29.954202       1 utils.go:199] ID: 6 GRPC request: {}
I0408 06:19:29.954218       1 utils.go:205] ID: 6 GRPC response: {}
I0408 06:19:29.956932       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0408 06:19:29.956949       1 utils.go:199] ID: 7 GRPC request: {}
I0408 06:19:29.956955       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0408 06:19:29.957015       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0408 06:19:29.959818       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0408 06:19:29.959958       1 utils.go:199] ID: 8 GRPC request: {}
I0408 06:19:29.960067       1 utils.go:205] ID: 8 GRPC response: {}
I0408 06:19:29.960620       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0408 06:19:29.960646       1 utils.go:199] ID: 9 GRPC request: {}
I0408 06:19:29.960732       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0408 06:19:29.961430       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0408 06:19:29.961451       1 utils.go:199] ID: 10 GRPC request: {}
I0408 06:19:29.961458       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0408 06:19:29.961592       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}}}]}
I0408 06:19:29.962078       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0408 06:19:29.962103       1 utils.go:199] ID: 11 GRPC request: {}
I0408 06:19:29.962108       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0408 06:19:29.962201       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}}}]}
I0408 06:19:29.962489       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0408 06:19:29.962515       1 utils.go:199] ID: 12 GRPC request: {}
I0408 06:19:29.962519       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0408 06:19:29.962615       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}}}]}
I0408 06:19:31.306222       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0408 06:19:31.306273       1 utils.go:199] ID: 13 GRPC request: {}
I0408 06:19:31.306286       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0408 06:19:31.306340       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0408 06:19:31.309197       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0408 06:19:31.309216       1 utils.go:199] ID: 14 GRPC request: {}
I0408 06:19:31.309228       1 utils.go:205] ID: 14 GRPC response: {}
I0408 06:19:31.309951       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0408 06:19:31.309978       1 utils.go:199] ID: 15 GRPC request: {}
I0408 06:19:31.309990       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0408 06:19:31.310078       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}}}]}
I0408 06:19:32.633324       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0408 06:19:32.633545       1 utils.go:199] ID: 16 GRPC request: {}
I0408 06:19:32.633636       1 utils.go:205] ID: 16 GRPC response: {}
I0408 06:19:32.636441       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0408 06:19:32.636478       1 utils.go:199] ID: 17 GRPC request: {}
I0408 06:19:32.636487       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0408 06:19:32.636511       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0408 06:19:32.640168       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0408 06:19:32.640187       1 utils.go:199] ID: 18 GRPC request: {}
I0408 06:19:32.640264       1 utils.go:205] ID: 18 GRPC response: {}
I0408 06:19:32.640728       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0408 06:19:32.640746       1 utils.go:199] ID: 19 GRPC request: {}
I0408 06:19:32.640913       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0408 06:19:32.641560       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0408 06:19:32.641579       1 utils.go:199] ID: 20 GRPC request: {}
I0408 06:19:32.641588       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0408 06:19:32.641763       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}}}]}
I0408 06:20:35.011779       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0408 06:20:35.011855       1 utils.go:199] ID: 21 GRPC request: {}
I0408 06:20:35.011878       1 utils.go:205] ID: 21 GRPC response: {}
I0408 06:21:35.011741       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0408 06:21:35.011800       1 utils.go:199] ID: 22 GRPC request: {}
I0408 06:21:35.011821       1 utils.go:205] ID: 22 GRPC response: {}
I0408 06:22:30.775383       1 utils.go:198] ID: 23 Req-ID: pvc-1aec82cc-e554-4664-8e21-dda735c10ac7 GRPC call: /csi.v1.Controller/CreateVolume
I0408 06:22:30.775812       1 utils.go:199] ID: 23 Req-ID: pvc-1aec82cc-e554-4664-8e21-dda735c10ac7 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-1aec82cc-e554-4664-8e21-dda735c10ac7","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-1aec82cc-e554-4664-8e21-dda735c10ac7","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}}]}
I0408 06:22:30.776353       1 rbd_util.go:1315] ID: 23 Req-ID: pvc-1aec82cc-e554-4664-8e21-dda735c10ac7 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0408 06:22:30.791355       1 omap.go:80] ID: 23 Req-ID: pvc-1aec82cc-e554-4664-8e21-dda735c10ac7 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0408 06:22:30.805165       1 omap.go:159] ID: 23 Req-ID: pvc-1aec82cc-e554-4664-8e21-dda735c10ac7 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-1aec82cc-e554-4664-8e21-dda735c10ac7:813fb9b5-a0b3-41a1-82fb-2d797b89e87e])
I0408 06:22:30.811183       1 omap.go:159] ID: 23 Req-ID: pvc-1aec82cc-e554-4664-8e21-dda735c10ac7 set omap keys (pool="kube", namespace="", name="csi.volume.813fb9b5-a0b3-41a1-82fb-2d797b89e87e"): map[csi.imagename:csi-vol-813fb9b5-a0b3-41a1-82fb-2d797b89e87e csi.volname:pvc-1aec82cc-e554-4664-8e21-dda735c10ac7 csi.volume.owner:default])
I0408 06:22:30.811290       1 rbd_journal.go:491] ID: 23 Req-ID: pvc-1aec82cc-e554-4664-8e21-dda735c10ac7 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-813fb9b5-a0b3-41a1-82fb-2d797b89e87e) and image name (csi-vol-813fb9b5-a0b3-41a1-82fb-2d797b89e87e) for request name (pvc-1aec82cc-e554-4664-8e21-dda735c10ac7)
I0408 06:22:30.811462       1 rbd_util.go:423] ID: 23 Req-ID: pvc-1aec82cc-e554-4664-8e21-dda735c10ac7 rbd: create kube/csi-vol-813fb9b5-a0b3-41a1-82fb-2d797b89e87e size 5120M (features: [layering]) using mon 199.204.45.6
I0408 06:22:30.811599       1 rbd_util.go:1563] ID: 23 Req-ID: pvc-1aec82cc-e554-4664-8e21-dda735c10ac7 setting image options on kube/csi-vol-813fb9b5-a0b3-41a1-82fb-2d797b89e87e
I0408 06:22:32.371127       1 controllerserver.go:763] ID: 23 Req-ID: pvc-1aec82cc-e554-4664-8e21-dda735c10ac7 created image kube/csi-vol-813fb9b5-a0b3-41a1-82fb-2d797b89e87e backed for request name pvc-1aec82cc-e554-4664-8e21-dda735c10ac7
I0408 06:22:32.404819       1 omap.go:159] ID: 23 Req-ID: pvc-1aec82cc-e554-4664-8e21-dda735c10ac7 set omap keys (pool="kube", namespace="", name="csi.volume.813fb9b5-a0b3-41a1-82fb-2d797b89e87e"): map[csi.imageid:37d9570e488c])
I0408 06:22:32.498846       1 utils.go:205] ID: 23 Req-ID: pvc-1aec82cc-e554-4664-8e21-dda735c10ac7 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-813fb9b5-a0b3-41a1-82fb-2d797b89e87e","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-813fb9b5-a0b3-41a1-82fb-2d797b89e87e"}}
I0408 06:22:35.011267       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0408 06:22:35.011514       1 utils.go:199] ID: 24 GRPC request: {}
I0408 06:22:35.011683       1 utils.go:205] ID: 24 GRPC response: {}