I0511 05:48:24.416827       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0511 05:48:24.417008       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0511 05:48:24.417024       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0511 05:48:24.417032       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0511 05:48:24.417035       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0511 05:48:24.417038       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0511 05:48:24.417042       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0511 05:48:24.417046       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0511 05:48:24.417049       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0511 05:48:24.417053       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0511 05:48:24.417378       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0511 05:48:24.417401       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0511 05:48:26.518471       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0511 05:48:26.519934       1 utils.go:199] ID: 1 GRPC request: {}
I0511 05:48:26.519999       1 utils.go:205] ID: 1 GRPC response: {}
I0511 05:48:26.524202       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0511 05:48:26.524253       1 utils.go:199] ID: 2 GRPC request: {}
I0511 05:48:26.524270       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0511 05:48:26.524325       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0511 05:48:26.526920       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0511 05:48:26.526943       1 utils.go:199] ID: 3 GRPC request: {}
I0511 05:48:26.526955       1 utils.go:205] ID: 3 GRPC response: {}
I0511 05:48:26.527634       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0511 05:48:26.527721       1 utils.go:199] ID: 4 GRPC request: {}
I0511 05:48:26.527894       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0511 05:48:26.529085       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0511 05:48:26.529222       1 utils.go:199] ID: 5 GRPC request: {}
I0511 05:48:26.529238       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0511 05:48:26.529414       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}}}]}
I0511 05:48:26.756643       1 utils.go:198] ID: 6 Req-ID: pvc-a3a7b4b7-fa00-4229-873e-cc190d698cab GRPC call: /csi.v1.Controller/CreateVolume
I0511 05:48:26.757067       1 utils.go:199] ID: 6 Req-ID: pvc-a3a7b4b7-fa00-4229-873e-cc190d698cab GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-a3a7b4b7-fa00-4229-873e-cc190d698cab","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-a3a7b4b7-fa00-4229-873e-cc190d698cab","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}}]}
I0511 05:48:26.757399       1 rbd_util.go:1315] ID: 6 Req-ID: pvc-a3a7b4b7-fa00-4229-873e-cc190d698cab setting disableInUseChecks: false image features: [layering] mounter: rbd
E0511 05:48:26.781563       1 omap.go:80] ID: 6 Req-ID: pvc-a3a7b4b7-fa00-4229-873e-cc190d698cab omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0511 05:48:26.797305       1 omap.go:159] ID: 6 Req-ID: pvc-a3a7b4b7-fa00-4229-873e-cc190d698cab set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-a3a7b4b7-fa00-4229-873e-cc190d698cab:dd5cd1db-2117-4f9e-8460-d0814630d7dd])
I0511 05:48:26.803048       1 omap.go:159] ID: 6 Req-ID: pvc-a3a7b4b7-fa00-4229-873e-cc190d698cab set omap keys (pool="kube", namespace="", name="csi.volume.dd5cd1db-2117-4f9e-8460-d0814630d7dd"): map[csi.imagename:csi-vol-dd5cd1db-2117-4f9e-8460-d0814630d7dd csi.volname:pvc-a3a7b4b7-fa00-4229-873e-cc190d698cab csi.volume.owner:default])
I0511 05:48:26.803087       1 rbd_journal.go:491] ID: 6 Req-ID: pvc-a3a7b4b7-fa00-4229-873e-cc190d698cab generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-dd5cd1db-2117-4f9e-8460-d0814630d7dd) and image name (csi-vol-dd5cd1db-2117-4f9e-8460-d0814630d7dd) for request name (pvc-a3a7b4b7-fa00-4229-873e-cc190d698cab)
I0511 05:48:26.803188       1 rbd_util.go:423] ID: 6 Req-ID: pvc-a3a7b4b7-fa00-4229-873e-cc190d698cab rbd: create kube/csi-vol-dd5cd1db-2117-4f9e-8460-d0814630d7dd size 5120M (features: [layering]) using mon 199.204.45.74
I0511 05:48:26.803233       1 rbd_util.go:1563] ID: 6 Req-ID: pvc-a3a7b4b7-fa00-4229-873e-cc190d698cab setting image options on kube/csi-vol-dd5cd1db-2117-4f9e-8460-d0814630d7dd
I0511 05:48:27.790530       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/Probe
I0511 05:48:27.790654       1 utils.go:199] ID: 7 GRPC request: {}
I0511 05:48:27.790692       1 utils.go:205] ID: 7 GRPC response: {}
I0511 05:48:27.794701       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/GetPluginInfo
I0511 05:48:27.794767       1 utils.go:199] ID: 8 GRPC request: {}
I0511 05:48:27.794781       1 identityserver-default.go:40] ID: 8 Using default GetPluginInfo
I0511 05:48:27.794819       1 utils.go:205] ID: 8 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0511 05:48:27.796935       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/Probe
I0511 05:48:27.796961       1 utils.go:199] ID: 9 GRPC request: {}
I0511 05:48:27.796978       1 utils.go:205] ID: 9 GRPC response: {}
I0511 05:48:27.797348       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0511 05:48:27.797369       1 utils.go:199] ID: 10 GRPC request: {}
I0511 05:48:27.797499       1 utils.go:205] ID: 10 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0511 05:48:27.798584       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0511 05:48:27.798630       1 utils.go:199] ID: 11 GRPC request: {}
I0511 05:48:27.798645       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0511 05:48:27.798720       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}}}]}
I0511 05:48:27.799621       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0511 05:48:27.799769       1 utils.go:199] ID: 12 GRPC request: {}
I0511 05:48:27.799790       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0511 05:48:27.800190       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}}}]}
I0511 05:48:27.800847       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0511 05:48:27.800891       1 utils.go:199] ID: 13 GRPC request: {}
I0511 05:48:27.800906       1 controllerserver-default.go:42] ID: 13 Using default ControllerGetCapabilities
I0511 05:48:27.801026       1 utils.go:205] ID: 13 GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}}]}
I0511 05:48:29.907991       1 controllerserver.go:763] ID: 6 Req-ID: pvc-a3a7b4b7-fa00-4229-873e-cc190d698cab created image kube/csi-vol-dd5cd1db-2117-4f9e-8460-d0814630d7dd backed for request name pvc-a3a7b4b7-fa00-4229-873e-cc190d698cab
I0511 05:48:30.154035       1 omap.go:159] ID: 6 Req-ID: pvc-a3a7b4b7-fa00-4229-873e-cc190d698cab set omap keys (pool="kube", namespace="", name="csi.volume.dd5cd1db-2117-4f9e-8460-d0814630d7dd"): map[csi.imageid:37b586ab9b7c])
I0511 05:48:30.241724       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/GetPluginInfo
I0511 05:48:30.241779       1 utils.go:199] ID: 14 GRPC request: {}
I0511 05:48:30.241797       1 identityserver-default.go:40] ID: 14 Using default GetPluginInfo
I0511 05:48:30.241837       1 utils.go:205] ID: 14 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0511 05:48:30.247350       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Identity/Probe
I0511 05:48:30.247415       1 utils.go:199] ID: 15 GRPC request: {}
I0511 05:48:30.247444       1 utils.go:205] ID: 15 GRPC response: {}
I0511 05:48:30.248358       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0511 05:48:30.248590       1 utils.go:199] ID: 16 GRPC request: {}
I0511 05:48:30.248617       1 controllerserver-default.go:42] ID: 16 Using default ControllerGetCapabilities
I0511 05:48:30.248927       1 utils.go:205] ID: 16 GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}}]}
I0511 05:48:30.252592       1 utils.go:205] ID: 6 Req-ID: pvc-a3a7b4b7-fa00-4229-873e-cc190d698cab GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-dd5cd1db-2117-4f9e-8460-d0814630d7dd","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-dd5cd1db-2117-4f9e-8460-d0814630d7dd"}}
I0511 05:48:31.666080       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/Probe
I0511 05:48:31.666122       1 utils.go:199] ID: 17 GRPC request: {}
I0511 05:48:31.666140       1 utils.go:205] ID: 17 GRPC response: {}
I0511 05:48:31.668707       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/GetPluginInfo
I0511 05:48:31.668731       1 utils.go:199] ID: 18 GRPC request: {}
I0511 05:48:31.668861       1 identityserver-default.go:40] ID: 18 Using default GetPluginInfo
I0511 05:48:31.668908       1 utils.go:205] ID: 18 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0511 05:48:31.671793       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/Probe
I0511 05:48:31.671819       1 utils.go:199] ID: 19 GRPC request: {}
I0511 05:48:31.671836       1 utils.go:205] ID: 19 GRPC response: {}
I0511 05:48:31.672154       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0511 05:48:31.672185       1 utils.go:199] ID: 20 GRPC request: {}
I0511 05:48:31.672296       1 utils.go:205] ID: 20 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0511 05:48:31.672988       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0511 05:48:31.673012       1 utils.go:199] ID: 21 GRPC request: {}
I0511 05:48:31.673022       1 controllerserver-default.go:42] ID: 21 Using default ControllerGetCapabilities
I0511 05:48:31.673153       1 utils.go:205] ID: 21 GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}}]}