I0203 22:37:11.748190       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0203 22:37:11.748471       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0203 22:37:11.748530       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0203 22:37:11.748581       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0203 22:37:11.748614       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0203 22:37:11.748682       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0203 22:37:11.748731       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0203 22:37:11.748776       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0203 22:37:11.748803       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0203 22:37:11.748863       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0203 22:37:11.749975       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0203 22:37:11.750150       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0203 22:37:14.814224       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0203 22:37:14.815337       1 utils.go:199] ID: 1 GRPC request: {}
I0203 22:37:14.815431       1 utils.go:205] ID: 1 GRPC response: {}
I0203 22:37:14.817800       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0203 22:37:14.817869       1 utils.go:199] ID: 2 GRPC request: {}
I0203 22:37:14.817884       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0203 22:37:14.817922       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0203 22:37:14.823218       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0203 22:37:14.823252       1 utils.go:199] ID: 3 GRPC request: {}
I0203 22:37:14.827460       1 utils.go:205] ID: 3 GRPC response: {}
I0203 22:37:14.828976       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0203 22:37:14.829112       1 utils.go:199] ID: 4 GRPC request: {}
I0203 22:37:14.829330       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0203 22:37:14.834268       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0203 22:37:14.834337       1 utils.go:199] ID: 5 GRPC request: {}
I0203 22:37:14.834348       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0203 22:37:14.834799       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}}}]}
I0203 22:37:17.237156       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0203 22:37:17.237199       1 utils.go:199] ID: 6 GRPC request: {}
I0203 22:37:17.237217       1 utils.go:205] ID: 6 GRPC response: {}
I0203 22:37:17.240052       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0203 22:37:17.240067       1 utils.go:199] ID: 7 GRPC request: {}
I0203 22:37:17.240088       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0203 22:37:17.240108       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0203 22:37:17.242128       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0203 22:37:17.242161       1 utils.go:199] ID: 8 GRPC request: {}
I0203 22:37:17.242209       1 utils.go:205] ID: 8 GRPC response: {}
I0203 22:37:17.245843       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0203 22:37:17.245869       1 utils.go:199] ID: 9 GRPC request: {}
I0203 22:37:17.246026       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0203 22:37:17.246599       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0203 22:37:17.246620       1 utils.go:199] ID: 10 GRPC request: {}
I0203 22:37:17.246633       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0203 22:37:17.246810       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}}}]}
I0203 22:37:17.247391       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0203 22:37:17.247410       1 utils.go:199] ID: 11 GRPC request: {}
I0203 22:37:17.247487       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0203 22:37:17.247604       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}}}]}
I0203 22:37:17.247982       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0203 22:37:17.248000       1 utils.go:199] ID: 12 GRPC request: {}
I0203 22:37:17.248007       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0203 22:37:17.248159       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}}}]}
I0203 22:37:19.342735       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0203 22:37:19.342840       1 utils.go:199] ID: 13 GRPC request: {}
I0203 22:37:19.342898       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0203 22:37:19.342979       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0203 22:37:19.346212       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0203 22:37:19.346246       1 utils.go:199] ID: 14 GRPC request: {}
I0203 22:37:19.346296       1 utils.go:205] ID: 14 GRPC response: {}
I0203 22:37:19.347205       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0203 22:37:19.347224       1 utils.go:199] ID: 15 GRPC request: {}
I0203 22:37:19.347238       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0203 22:37:19.347388       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}}}]}
I0203 22:37:21.642779       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0203 22:37:21.642816       1 utils.go:199] ID: 16 GRPC request: {}
I0203 22:37:21.642836       1 utils.go:205] ID: 16 GRPC response: {}
I0203 22:37:21.645266       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0203 22:37:21.645310       1 utils.go:199] ID: 17 GRPC request: {}
I0203 22:37:21.645326       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0203 22:37:21.645348       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0203 22:37:21.648176       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0203 22:37:21.648202       1 utils.go:199] ID: 18 GRPC request: {}
I0203 22:37:21.648218       1 utils.go:205] ID: 18 GRPC response: {}
I0203 22:37:21.648664       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0203 22:37:21.648691       1 utils.go:199] ID: 19 GRPC request: {}
I0203 22:37:21.648781       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0203 22:37:21.649245       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0203 22:37:21.649272       1 utils.go:199] ID: 20 GRPC request: {}
I0203 22:37:21.649289       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0203 22:37:21.649354       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}}}]}
I0203 22:38:22.116644       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0203 22:38:22.117030       1 utils.go:199] ID: 21 GRPC request: {}
I0203 22:38:22.117174       1 utils.go:205] ID: 21 GRPC response: {}
I0203 22:39:22.114324       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0203 22:39:22.114362       1 utils.go:199] ID: 22 GRPC request: {}
I0203 22:39:22.114375       1 utils.go:205] ID: 22 GRPC response: {}
I0203 22:40:16.565728       1 utils.go:198] ID: 23 Req-ID: pvc-3e35cd2b-a1f7-45c7-854b-68c63d45fa16 GRPC call: /csi.v1.Controller/CreateVolume
I0203 22:40:16.566408       1 utils.go:199] ID: 23 Req-ID: pvc-3e35cd2b-a1f7-45c7-854b-68c63d45fa16 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-3e35cd2b-a1f7-45c7-854b-68c63d45fa16","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-3e35cd2b-a1f7-45c7-854b-68c63d45fa16","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}}]}
I0203 22:40:16.566716       1 rbd_util.go:1315] ID: 23 Req-ID: pvc-3e35cd2b-a1f7-45c7-854b-68c63d45fa16 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0203 22:40:16.621807       1 omap.go:80] ID: 23 Req-ID: pvc-3e35cd2b-a1f7-45c7-854b-68c63d45fa16 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0203 22:40:16.639256       1 omap.go:159] ID: 23 Req-ID: pvc-3e35cd2b-a1f7-45c7-854b-68c63d45fa16 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-3e35cd2b-a1f7-45c7-854b-68c63d45fa16:089c8b01-9cb0-4a5a-879c-346bc0ce6e95])
I0203 22:40:16.644965       1 omap.go:159] ID: 23 Req-ID: pvc-3e35cd2b-a1f7-45c7-854b-68c63d45fa16 set omap keys (pool="kube", namespace="", name="csi.volume.089c8b01-9cb0-4a5a-879c-346bc0ce6e95"): map[csi.imagename:csi-vol-089c8b01-9cb0-4a5a-879c-346bc0ce6e95 csi.volname:pvc-3e35cd2b-a1f7-45c7-854b-68c63d45fa16 csi.volume.owner:default])
I0203 22:40:16.644983       1 rbd_journal.go:491] ID: 23 Req-ID: pvc-3e35cd2b-a1f7-45c7-854b-68c63d45fa16 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-089c8b01-9cb0-4a5a-879c-346bc0ce6e95) and image name (csi-vol-089c8b01-9cb0-4a5a-879c-346bc0ce6e95) for request name (pvc-3e35cd2b-a1f7-45c7-854b-68c63d45fa16)
I0203 22:40:16.645036       1 rbd_util.go:423] ID: 23 Req-ID: pvc-3e35cd2b-a1f7-45c7-854b-68c63d45fa16 rbd: create kube/csi-vol-089c8b01-9cb0-4a5a-879c-346bc0ce6e95 size 5120M (features: [layering]) using mon 162.253.55.200
I0203 22:40:16.645075       1 rbd_util.go:1563] ID: 23 Req-ID: pvc-3e35cd2b-a1f7-45c7-854b-68c63d45fa16 setting image options on kube/csi-vol-089c8b01-9cb0-4a5a-879c-346bc0ce6e95
I0203 22:40:18.067051       1 controllerserver.go:763] ID: 23 Req-ID: pvc-3e35cd2b-a1f7-45c7-854b-68c63d45fa16 created image kube/csi-vol-089c8b01-9cb0-4a5a-879c-346bc0ce6e95 backed for request name pvc-3e35cd2b-a1f7-45c7-854b-68c63d45fa16
I0203 22:40:18.097446       1 omap.go:159] ID: 23 Req-ID: pvc-3e35cd2b-a1f7-45c7-854b-68c63d45fa16 set omap keys (pool="kube", namespace="", name="csi.volume.089c8b01-9cb0-4a5a-879c-346bc0ce6e95"): map[csi.imageid:37d931e655c2])
I0203 22:40:18.170189       1 utils.go:205] ID: 23 Req-ID: pvc-3e35cd2b-a1f7-45c7-854b-68c63d45fa16 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-089c8b01-9cb0-4a5a-879c-346bc0ce6e95","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-089c8b01-9cb0-4a5a-879c-346bc0ce6e95"}}
I0203 22:40:22.117086       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0203 22:40:22.117147       1 utils.go:199] ID: 24 GRPC request: {}
I0203 22:40:22.117182       1 utils.go:205] ID: 24 GRPC response: {}