I0428 06:55:18.154092       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0428 06:55:18.154210       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0428 06:55:18.154221       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0428 06:55:18.154225       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0428 06:55:18.154228       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0428 06:55:18.154234       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0428 06:55:18.154239       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0428 06:55:18.154242       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0428 06:55:18.154245       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0428 06:55:18.154249       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0428 06:55:18.154659       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0428 06:55:18.154828       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0428 06:55:21.954941       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0428 06:55:21.956423       1 utils.go:199] ID: 1 GRPC request: {}
I0428 06:55:21.956483       1 utils.go:205] ID: 1 GRPC response: {}
I0428 06:55:21.959452       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0428 06:55:21.959714       1 utils.go:199] ID: 2 GRPC request: {}
I0428 06:55:21.959829       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0428 06:55:21.960044       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0428 06:55:21.962794       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0428 06:55:21.962820       1 utils.go:199] ID: 3 GRPC request: {}
I0428 06:55:21.962832       1 utils.go:205] ID: 3 GRPC response: {}
I0428 06:55:21.963340       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0428 06:55:21.963572       1 utils.go:199] ID: 4 GRPC request: {}
I0428 06:55:21.963886       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0428 06:55:21.965396       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0428 06:55:21.965502       1 utils.go:199] ID: 5 GRPC request: {}
I0428 06:55:21.965519       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0428 06:55:21.965770       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}}}]}
I0428 06:55:28.047958       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0428 06:55:28.047996       1 utils.go:199] ID: 6 GRPC request: {}
I0428 06:55:28.048014       1 utils.go:205] ID: 6 GRPC response: {}
I0428 06:55:28.051533       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0428 06:55:28.051563       1 utils.go:199] ID: 7 GRPC request: {}
I0428 06:55:28.051571       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0428 06:55:28.051596       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0428 06:55:28.053459       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0428 06:55:28.053488       1 utils.go:199] ID: 8 GRPC request: {}
I0428 06:55:28.053499       1 utils.go:205] ID: 8 GRPC response: {}
I0428 06:55:28.054101       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0428 06:55:28.054141       1 utils.go:199] ID: 9 GRPC request: {}
I0428 06:55:28.054258       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0428 06:55:28.054908       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0428 06:55:28.054957       1 utils.go:199] ID: 10 GRPC request: {}
I0428 06:55:28.055024       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0428 06:55:28.055157       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}}}]}
I0428 06:55:28.055740       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0428 06:55:28.055794       1 utils.go:199] ID: 11 GRPC request: {}
I0428 06:55:28.055806       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0428 06:55:28.055910       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}}}]}
I0428 06:55:28.056331       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0428 06:55:28.056351       1 utils.go:199] ID: 12 GRPC request: {}
I0428 06:55:28.056357       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0428 06:55:28.056522       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}}}]}
I0428 06:55:29.784077       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0428 06:55:29.784111       1 utils.go:199] ID: 13 GRPC request: {}
I0428 06:55:29.784122       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0428 06:55:29.784147       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0428 06:55:29.787279       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0428 06:55:29.787325       1 utils.go:199] ID: 14 GRPC request: {}
I0428 06:55:29.787355       1 utils.go:205] ID: 14 GRPC response: {}
I0428 06:55:29.787749       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0428 06:55:29.787793       1 utils.go:199] ID: 15 GRPC request: {}
I0428 06:55:29.787815       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0428 06:55:29.787935       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}}}]}
I0428 06:55:31.118808       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0428 06:55:31.118871       1 utils.go:199] ID: 16 GRPC request: {}
I0428 06:55:31.118895       1 utils.go:205] ID: 16 GRPC response: {}
I0428 06:55:31.120589       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0428 06:55:31.120624       1 utils.go:199] ID: 17 GRPC request: {}
I0428 06:55:31.120635       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0428 06:55:31.120670       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0428 06:55:31.121979       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0428 06:55:31.121999       1 utils.go:199] ID: 18 GRPC request: {}
I0428 06:55:31.122015       1 utils.go:205] ID: 18 GRPC response: {}
I0428 06:55:31.122272       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0428 06:55:31.122297       1 utils.go:199] ID: 19 GRPC request: {}
I0428 06:55:31.122400       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0428 06:55:31.122864       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0428 06:55:31.122881       1 utils.go:199] ID: 20 GRPC request: {}
I0428 06:55:31.122889       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0428 06:55:31.122963       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}}}]}
I0428 06:56:31.330933       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0428 06:56:31.331008       1 utils.go:199] ID: 21 GRPC request: {}
I0428 06:56:31.331059       1 utils.go:205] ID: 21 GRPC response: {}
I0428 06:57:31.292622       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0428 06:57:31.292750       1 utils.go:199] ID: 22 GRPC request: {}
I0428 06:57:31.292921       1 utils.go:205] ID: 22 GRPC response: {}
I0428 06:58:28.375282       1 utils.go:198] ID: 23 Req-ID: pvc-99f9091c-7e1d-4758-a904-24024127ed4a GRPC call: /csi.v1.Controller/CreateVolume
I0428 06:58:28.375560       1 utils.go:199] ID: 23 Req-ID: pvc-99f9091c-7e1d-4758-a904-24024127ed4a GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-99f9091c-7e1d-4758-a904-24024127ed4a","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-99f9091c-7e1d-4758-a904-24024127ed4a","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}}]}
I0428 06:58:28.375723       1 rbd_util.go:1315] ID: 23 Req-ID: pvc-99f9091c-7e1d-4758-a904-24024127ed4a setting disableInUseChecks: false image features: [layering] mounter: rbd
E0428 06:58:28.389460       1 omap.go:80] ID: 23 Req-ID: pvc-99f9091c-7e1d-4758-a904-24024127ed4a omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0428 06:58:28.403993       1 omap.go:159] ID: 23 Req-ID: pvc-99f9091c-7e1d-4758-a904-24024127ed4a set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-99f9091c-7e1d-4758-a904-24024127ed4a:4c62d72c-e1d6-43b5-b759-1b80fb5b2293])
I0428 06:58:28.410668       1 omap.go:159] ID: 23 Req-ID: pvc-99f9091c-7e1d-4758-a904-24024127ed4a set omap keys (pool="kube", namespace="", name="csi.volume.4c62d72c-e1d6-43b5-b759-1b80fb5b2293"): map[csi.imagename:csi-vol-4c62d72c-e1d6-43b5-b759-1b80fb5b2293 csi.volname:pvc-99f9091c-7e1d-4758-a904-24024127ed4a csi.volume.owner:default])
I0428 06:58:28.410706       1 rbd_journal.go:491] ID: 23 Req-ID: pvc-99f9091c-7e1d-4758-a904-24024127ed4a generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-4c62d72c-e1d6-43b5-b759-1b80fb5b2293) and image name (csi-vol-4c62d72c-e1d6-43b5-b759-1b80fb5b2293) for request name (pvc-99f9091c-7e1d-4758-a904-24024127ed4a)
I0428 06:58:28.410811       1 rbd_util.go:423] ID: 23 Req-ID: pvc-99f9091c-7e1d-4758-a904-24024127ed4a rbd: create kube/csi-vol-4c62d72c-e1d6-43b5-b759-1b80fb5b2293 size 5120M (features: [layering]) using mon 199.204.45.156
I0428 06:58:28.410914       1 rbd_util.go:1563] ID: 23 Req-ID: pvc-99f9091c-7e1d-4758-a904-24024127ed4a setting image options on kube/csi-vol-4c62d72c-e1d6-43b5-b759-1b80fb5b2293
I0428 06:58:30.435085       1 controllerserver.go:763] ID: 23 Req-ID: pvc-99f9091c-7e1d-4758-a904-24024127ed4a created image kube/csi-vol-4c62d72c-e1d6-43b5-b759-1b80fb5b2293 backed for request name pvc-99f9091c-7e1d-4758-a904-24024127ed4a
I0428 06:58:30.466710       1 omap.go:159] ID: 23 Req-ID: pvc-99f9091c-7e1d-4758-a904-24024127ed4a set omap keys (pool="kube", namespace="", name="csi.volume.4c62d72c-e1d6-43b5-b759-1b80fb5b2293"): map[csi.imageid:37d9477c9fae])
I0428 06:58:30.563488       1 utils.go:205] ID: 23 Req-ID: pvc-99f9091c-7e1d-4758-a904-24024127ed4a GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-4c62d72c-e1d6-43b5-b759-1b80fb5b2293","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-4c62d72c-e1d6-43b5-b759-1b80fb5b2293"}}
I0428 06:58:31.345463       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0428 06:58:31.345548       1 utils.go:199] ID: 24 GRPC request: {}
I0428 06:58:31.345576       1 utils.go:205] ID: 24 GRPC response: {}