I0512 05:47:21.244304       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0512 05:47:21.244448       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0512 05:47:21.244463       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0512 05:47:21.244468       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0512 05:47:21.244470       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0512 05:47:21.244473       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0512 05:47:21.244477       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0512 05:47:21.244480       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0512 05:47:21.244482       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0512 05:47:21.244486       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0512 05:47:21.244922       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0512 05:47:21.245133       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0512 05:47:26.641600       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0512 05:47:26.643705       1 utils.go:199] ID: 1 GRPC request: {}
I0512 05:47:26.643896       1 utils.go:205] ID: 1 GRPC response: {}
I0512 05:47:26.646956       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0512 05:47:26.647006       1 utils.go:199] ID: 2 GRPC request: {}
I0512 05:47:26.647014       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0512 05:47:26.647062       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0512 05:47:26.648878       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0512 05:47:26.648899       1 utils.go:199] ID: 3 GRPC request: {}
I0512 05:47:26.648917       1 utils.go:205] ID: 3 GRPC response: {}
I0512 05:47:26.649761       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0512 05:47:26.649806       1 utils.go:199] ID: 4 GRPC request: {}
I0512 05:47:26.650025       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0512 05:47:26.650836       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0512 05:47:26.650879       1 utils.go:199] ID: 5 GRPC request: {}
I0512 05:47:26.650954       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0512 05:47:26.651162       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}}}]}
I0512 05:47:30.248176       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0512 05:47:30.248309       1 utils.go:199] ID: 6 GRPC request: {}
I0512 05:47:30.248370       1 utils.go:205] ID: 6 GRPC response: {}
I0512 05:47:30.251209       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0512 05:47:30.251307       1 utils.go:199] ID: 7 GRPC request: {}
I0512 05:47:30.251384       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0512 05:47:30.251467       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0512 05:47:30.254094       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0512 05:47:30.254188       1 utils.go:199] ID: 8 GRPC request: {}
I0512 05:47:30.254262       1 utils.go:205] ID: 8 GRPC response: {}
I0512 05:47:30.255082       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0512 05:47:30.255190       1 utils.go:199] ID: 9 GRPC request: {}
I0512 05:47:30.255395       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0512 05:47:30.256439       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0512 05:47:30.256521       1 utils.go:199] ID: 10 GRPC request: {}
I0512 05:47:30.256583       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0512 05:47:30.256851       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}}}]}
I0512 05:47:30.258225       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0512 05:47:30.258310       1 utils.go:199] ID: 11 GRPC request: {}
I0512 05:47:30.258345       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0512 05:47:30.258539       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}}}]}
I0512 05:47:30.260427       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0512 05:47:30.260487       1 utils.go:199] ID: 12 GRPC request: {}
I0512 05:47:30.260506       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0512 05:47:30.260671       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}}}]}
I0512 05:47:31.607804       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0512 05:47:31.607860       1 utils.go:199] ID: 13 GRPC request: {}
I0512 05:47:31.607869       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0512 05:47:31.607901       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0512 05:47:31.612044       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0512 05:47:31.612103       1 utils.go:199] ID: 14 GRPC request: {}
I0512 05:47:31.612140       1 utils.go:205] ID: 14 GRPC response: {}
I0512 05:47:31.612755       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0512 05:47:31.612785       1 utils.go:199] ID: 15 GRPC request: {}
I0512 05:47:31.612801       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0512 05:47:31.612909       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}}}]}
I0512 05:47:33.888621       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0512 05:47:33.889274       1 utils.go:199] ID: 16 GRPC request: {}
I0512 05:47:33.889305       1 utils.go:205] ID: 16 GRPC response: {}
I0512 05:47:33.892375       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0512 05:47:33.892443       1 utils.go:199] ID: 17 GRPC request: {}
I0512 05:47:33.892461       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0512 05:47:33.892507       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0512 05:47:33.896523       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0512 05:47:33.896587       1 utils.go:199] ID: 18 GRPC request: {}
I0512 05:47:33.896657       1 utils.go:205] ID: 18 GRPC response: {}
I0512 05:47:33.897503       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0512 05:47:33.897591       1 utils.go:199] ID: 19 GRPC request: {}
I0512 05:47:33.898327       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0512 05:47:33.899259       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0512 05:47:33.899282       1 utils.go:199] ID: 20 GRPC request: {}
I0512 05:47:33.899838       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0512 05:47:33.899918       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}}}]}
I0512 05:48:34.239097       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0512 05:48:34.239155       1 utils.go:199] ID: 21 GRPC request: {}
I0512 05:48:34.239181       1 utils.go:205] ID: 21 GRPC response: {}
I0512 05:49:34.182783       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0512 05:49:34.182915       1 utils.go:199] ID: 22 GRPC request: {}
I0512 05:49:34.182932       1 utils.go:205] ID: 22 GRPC response: {}
I0512 05:50:34.183683       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0512 05:50:34.183734       1 utils.go:199] ID: 23 GRPC request: {}
I0512 05:50:34.183759       1 utils.go:205] ID: 23 GRPC response: {}
I0512 05:50:49.172107       1 utils.go:198] ID: 24 Req-ID: pvc-19627b99-3415-41b8-9800-2dcc059bea82 GRPC call: /csi.v1.Controller/CreateVolume
I0512 05:50:49.172606       1 utils.go:199] ID: 24 Req-ID: pvc-19627b99-3415-41b8-9800-2dcc059bea82 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-19627b99-3415-41b8-9800-2dcc059bea82","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-19627b99-3415-41b8-9800-2dcc059bea82","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}}]}
I0512 05:50:49.172930       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-19627b99-3415-41b8-9800-2dcc059bea82 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0512 05:50:49.192214       1 omap.go:80] ID: 24 Req-ID: pvc-19627b99-3415-41b8-9800-2dcc059bea82 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0512 05:50:49.208972       1 omap.go:159] ID: 24 Req-ID: pvc-19627b99-3415-41b8-9800-2dcc059bea82 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-19627b99-3415-41b8-9800-2dcc059bea82:5eb59dc8-5442-491e-9d81-8a2f5d35294a])
I0512 05:50:49.216389       1 omap.go:159] ID: 24 Req-ID: pvc-19627b99-3415-41b8-9800-2dcc059bea82 set omap keys (pool="kube", namespace="", name="csi.volume.5eb59dc8-5442-491e-9d81-8a2f5d35294a"): map[csi.imagename:csi-vol-5eb59dc8-5442-491e-9d81-8a2f5d35294a csi.volname:pvc-19627b99-3415-41b8-9800-2dcc059bea82 csi.volume.owner:default])
I0512 05:50:49.216419       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-19627b99-3415-41b8-9800-2dcc059bea82 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-5eb59dc8-5442-491e-9d81-8a2f5d35294a) and image name (csi-vol-5eb59dc8-5442-491e-9d81-8a2f5d35294a) for request name (pvc-19627b99-3415-41b8-9800-2dcc059bea82)
I0512 05:50:49.216617       1 rbd_util.go:423] ID: 24 Req-ID: pvc-19627b99-3415-41b8-9800-2dcc059bea82 rbd: create kube/csi-vol-5eb59dc8-5442-491e-9d81-8a2f5d35294a size 5120M (features: [layering]) using mon 199.204.45.38
I0512 05:50:49.216767       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-19627b99-3415-41b8-9800-2dcc059bea82 setting image options on kube/csi-vol-5eb59dc8-5442-491e-9d81-8a2f5d35294a
I0512 05:50:51.114492       1 controllerserver.go:763] ID: 24 Req-ID: pvc-19627b99-3415-41b8-9800-2dcc059bea82 created image kube/csi-vol-5eb59dc8-5442-491e-9d81-8a2f5d35294a backed for request name pvc-19627b99-3415-41b8-9800-2dcc059bea82
I0512 05:50:51.151252       1 omap.go:159] ID: 24 Req-ID: pvc-19627b99-3415-41b8-9800-2dcc059bea82 set omap keys (pool="kube", namespace="", name="csi.volume.5eb59dc8-5442-491e-9d81-8a2f5d35294a"): map[csi.imageid:37d96ec5902])
I0512 05:50:51.256006       1 utils.go:205] ID: 24 Req-ID: pvc-19627b99-3415-41b8-9800-2dcc059bea82 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-5eb59dc8-5442-491e-9d81-8a2f5d35294a","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-5eb59dc8-5442-491e-9d81-8a2f5d35294a"}}
I0512 05:51:34.197172       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0512 05:51:34.197212       1 utils.go:199] ID: 25 GRPC request: {}
I0512 05:51:34.197227       1 utils.go:205] ID: 25 GRPC response: {}