I0218 14:45:17.437990       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0218 14:45:17.438288       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0218 14:45:17.438303       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0218 14:45:17.438307       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0218 14:45:17.438310       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0218 14:45:17.438312       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0218 14:45:17.438318       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0218 14:45:17.438321       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0218 14:45:17.438323       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0218 14:45:17.438329       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0218 14:45:17.439009       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0218 14:45:17.439042       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0218 14:45:20.565210       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0218 14:45:20.566238       1 utils.go:199] ID: 1 GRPC request: {}
I0218 14:45:20.566332       1 utils.go:205] ID: 1 GRPC response: {}
I0218 14:45:20.568593       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0218 14:45:20.568679       1 utils.go:199] ID: 2 GRPC request: {}
I0218 14:45:20.568693       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0218 14:45:20.568774       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0218 14:45:20.570835       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0218 14:45:20.570850       1 utils.go:199] ID: 3 GRPC request: {}
I0218 14:45:20.570858       1 utils.go:205] ID: 3 GRPC response: {}
I0218 14:45:20.574066       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0218 14:45:20.574171       1 utils.go:199] ID: 4 GRPC request: {}
I0218 14:45:20.574333       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0218 14:45:20.574921       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0218 14:45:20.575026       1 utils.go:199] ID: 5 GRPC request: {}
I0218 14:45:20.575041       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0218 14:45:20.575187       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}}}]}
I0218 14:45:23.360767       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0218 14:45:23.360845       1 utils.go:199] ID: 6 GRPC request: {}
I0218 14:45:23.360863       1 utils.go:205] ID: 6 GRPC response: {}
I0218 14:45:23.364219       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0218 14:45:23.364234       1 utils.go:199] ID: 7 GRPC request: {}
I0218 14:45:23.364252       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0218 14:45:23.364269       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0218 14:45:23.365336       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0218 14:45:23.365363       1 utils.go:199] ID: 8 GRPC request: {}
I0218 14:45:23.365387       1 utils.go:205] ID: 8 GRPC response: {}
I0218 14:45:23.365770       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0218 14:45:23.365786       1 utils.go:199] ID: 9 GRPC request: {}
I0218 14:45:23.365916       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0218 14:45:23.366360       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0218 14:45:23.366380       1 utils.go:199] ID: 10 GRPC request: {}
I0218 14:45:23.366460       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0218 14:45:23.366573       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}}}]}
I0218 14:45:23.366911       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0218 14:45:23.366924       1 utils.go:199] ID: 11 GRPC request: {}
I0218 14:45:23.366969       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0218 14:45:23.367048       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}}}]}
I0218 14:45:23.367311       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0218 14:45:23.367324       1 utils.go:199] ID: 12 GRPC request: {}
I0218 14:45:23.367328       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0218 14:45:23.367456       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}}}]}
I0218 14:45:33.080673       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0218 14:45:33.080706       1 utils.go:199] ID: 13 GRPC request: {}
I0218 14:45:33.080855       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0218 14:45:33.080916       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0218 14:45:33.085456       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0218 14:45:33.085477       1 utils.go:199] ID: 14 GRPC request: {}
I0218 14:45:33.085489       1 utils.go:205] ID: 14 GRPC response: {}
I0218 14:45:33.085811       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0218 14:45:33.085826       1 utils.go:199] ID: 15 GRPC request: {}
I0218 14:45:33.085832       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0218 14:45:33.085927       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}}}]}
I0218 14:45:36.087748       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0218 14:45:36.087808       1 utils.go:199] ID: 16 GRPC request: {}
I0218 14:45:36.087840       1 utils.go:205] ID: 16 GRPC response: {}
I0218 14:45:36.106198       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0218 14:45:36.106287       1 utils.go:199] ID: 17 GRPC request: {}
I0218 14:45:36.106304       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0218 14:45:36.106335       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0218 14:45:36.110918       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0218 14:45:36.111157       1 utils.go:199] ID: 18 GRPC request: {}
I0218 14:45:36.111242       1 utils.go:205] ID: 18 GRPC response: {}
I0218 14:45:36.112050       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0218 14:45:36.113903       1 utils.go:199] ID: 19 GRPC request: {}
I0218 14:45:36.114252       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0218 14:45:36.119571       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0218 14:45:36.119631       1 utils.go:199] ID: 20 GRPC request: {}
I0218 14:45:36.119659       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0218 14:45:36.119786       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}}}]}
I0218 14:46:36.708432       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0218 14:46:36.708489       1 utils.go:199] ID: 21 GRPC request: {}
I0218 14:46:36.708510       1 utils.go:205] ID: 21 GRPC response: {}
I0218 14:47:36.707904       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0218 14:47:36.707946       1 utils.go:199] ID: 22 GRPC request: {}
I0218 14:47:36.707969       1 utils.go:205] ID: 22 GRPC response: {}
I0218 14:48:29.955007       1 utils.go:198] ID: 23 Req-ID: pvc-ab31ca28-dc95-4254-8322-fe2a4a6fbb3b GRPC call: /csi.v1.Controller/CreateVolume
I0218 14:48:29.955423       1 utils.go:199] ID: 23 Req-ID: pvc-ab31ca28-dc95-4254-8322-fe2a4a6fbb3b GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-ab31ca28-dc95-4254-8322-fe2a4a6fbb3b","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-ab31ca28-dc95-4254-8322-fe2a4a6fbb3b","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}}]}
I0218 14:48:29.955687       1 rbd_util.go:1315] ID: 23 Req-ID: pvc-ab31ca28-dc95-4254-8322-fe2a4a6fbb3b setting disableInUseChecks: false image features: [layering] mounter: rbd
E0218 14:48:29.973873       1 omap.go:80] ID: 23 Req-ID: pvc-ab31ca28-dc95-4254-8322-fe2a4a6fbb3b omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0218 14:48:30.385775       1 omap.go:159] ID: 23 Req-ID: pvc-ab31ca28-dc95-4254-8322-fe2a4a6fbb3b set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-ab31ca28-dc95-4254-8322-fe2a4a6fbb3b:1b8b001d-d190-4a51-b76b-efc28094cbdf])
I0218 14:48:30.784877       1 omap.go:159] ID: 23 Req-ID: pvc-ab31ca28-dc95-4254-8322-fe2a4a6fbb3b set omap keys (pool="kube", namespace="", name="csi.volume.1b8b001d-d190-4a51-b76b-efc28094cbdf"): map[csi.imagename:csi-vol-1b8b001d-d190-4a51-b76b-efc28094cbdf csi.volname:pvc-ab31ca28-dc95-4254-8322-fe2a4a6fbb3b csi.volume.owner:default])
I0218 14:48:30.785282       1 rbd_journal.go:491] ID: 23 Req-ID: pvc-ab31ca28-dc95-4254-8322-fe2a4a6fbb3b generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-1b8b001d-d190-4a51-b76b-efc28094cbdf) and image name (csi-vol-1b8b001d-d190-4a51-b76b-efc28094cbdf) for request name (pvc-ab31ca28-dc95-4254-8322-fe2a4a6fbb3b)
I0218 14:48:30.785437       1 rbd_util.go:423] ID: 23 Req-ID: pvc-ab31ca28-dc95-4254-8322-fe2a4a6fbb3b rbd: create kube/csi-vol-1b8b001d-d190-4a51-b76b-efc28094cbdf size 5120M (features: [layering]) using mon 162.253.55.227
I0218 14:48:30.785526       1 rbd_util.go:1563] ID: 23 Req-ID: pvc-ab31ca28-dc95-4254-8322-fe2a4a6fbb3b setting image options on kube/csi-vol-1b8b001d-d190-4a51-b76b-efc28094cbdf
I0218 14:48:32.504773       1 controllerserver.go:763] ID: 23 Req-ID: pvc-ab31ca28-dc95-4254-8322-fe2a4a6fbb3b created image kube/csi-vol-1b8b001d-d190-4a51-b76b-efc28094cbdf backed for request name pvc-ab31ca28-dc95-4254-8322-fe2a4a6fbb3b
I0218 14:48:32.540698       1 omap.go:159] ID: 23 Req-ID: pvc-ab31ca28-dc95-4254-8322-fe2a4a6fbb3b set omap keys (pool="kube", namespace="", name="csi.volume.1b8b001d-d190-4a51-b76b-efc28094cbdf"): map[csi.imageid:37d8e5a42325])
I0218 14:48:32.667132       1 utils.go:205] ID: 23 Req-ID: pvc-ab31ca28-dc95-4254-8322-fe2a4a6fbb3b GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-1b8b001d-d190-4a51-b76b-efc28094cbdf","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-1b8b001d-d190-4a51-b76b-efc28094cbdf"}}
I0218 14:48:36.707563       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0218 14:48:36.707938       1 utils.go:199] ID: 24 GRPC request: {}
I0218 14:48:36.708181       1 utils.go:205] ID: 24 GRPC response: {}