Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Create a new cephfs PVC from snapshot fails #5060

Open
sle78 opened this issue Jan 8, 2025 · 5 comments
Open

Create a new cephfs PVC from snapshot fails #5060

sle78 opened this issue Jan 8, 2025 · 5 comments
Labels
component/cephfs Issues related to CephFS

Comments

@sle78
Copy link

sle78 commented Jan 8, 2025 •
edited
Loading

Describe the bug

Creating a new cephfs PVC from snapshot is failing.

Environment details

  • Image/version of Ceph CSI driver : 8.13.0
  • Helm chart version :
  • Kernel version : 5.15.0-130-generic
  • Mounter used for mounting PVC (for cephFS its fuse or kernel. for rbd its
    krbd or rbd-nbd) : N/A
  • Kubernetes cluster version : v1.30.8
  • Ceph cluster version :
{
    "mon": {
        "ceph version 19.2.0 (16063ff2022298c9300e49a547a16ffda59baf13) squid (stable)": 3
    },
    "mgr": {
        "ceph version 19.2.0 (16063ff2022298c9300e49a547a16ffda59baf13) squid (stable)": 2
    },
    "osd": {
        "ceph version 19.2.0 (16063ff2022298c9300e49a547a16ffda59baf13) squid (stable)": 34
    },
    "mds": {
        "ceph version 19.2.0 (16063ff2022298c9300e49a547a16ffda59baf13) squid (stable)": 2
    },
    "rgw": {
        "ceph version 19.2.0 (16063ff2022298c9300e49a547a16ffda59baf13) squid (stable)": 2
    },
    "overall": {
        "ceph version 19.2.0 (16063ff2022298c9300e49a547a16ffda59baf13) squid (stable)": 43
    }
}

rook-ceph-provisioner stack

    Image:      registry.k8s.io/sig-storage/csi-attacher:v4.6.1
    Image:      registry.k8s.io/sig-storage/csi-snapshotter:v8.2.0
    Image:      registry.k8s.io/sig-storage/csi-resizer:v1.11.1
    Image:      registry.k8s.io/sig-storage/csi-provisioner:v5.0.1
    Image:      quay.io/cephcsi/cephcsi:v3.13.0
    Image:      quay.io/cephcsi/cephcsi:v3.13.0

Steps to reproduce

Create a new cephfs PVC from snapshot

Name:          create-mn-k8s-snapshot-bdf4f0a5-0b7f-4572-977a-ff3ef1db402d-a969c600-4ff1-4c58-be99-f2f09de50f92-0-0-eae92200-4353-440b-8123-217991f95a56
Namespace:     data
StorageClass:  ceph-filesystem
Status:        Pending
Volume:        
Annotations:   volume.beta.kubernetes.io/storage-provisioner: storage.cephfs.csi.ceph.com
               volume.kubernetes.io/storage-provisioner: storage.cephfs.csi.ceph.com
Finalizers:    [kubernetes.io/pvc-protection]
Capacity:      
Access Modes:  
VolumeMode:    Filesystem
DataSource:
  APIGroup:  snapshot.storage.k8s.io
  Kind:      VolumeSnapshot
  Name:      data-fs-datasp58f
Events:
  Warning  ProvisioningFailed    103s                storage.cephfs.csi.ceph.com_csi-cephfsplugin-provisioner-6b5b5b49c5-f5t88_47b8f641-6a63-4d09-ad08-0359f1b6a9ee  failed to provision volume with StorageClass "ceph-filesystem": rpc error: code = Aborted desc = clone from snapshot is pending
  Normal   Provisioning          30s (x8 over 104s)  storage.cephfs.csi.ceph.com_csi-cephfsplugin-provisioner-6b5b5b49c5-f5t88_47b8f641-6a63-4d09-ad08-0359f1b6a9ee  External provisioner is provisioning volume for claim "data/create-mn-k8s-snapshot-bdf4f0a5-0b7f-4572-977a-ff3ef1db402d-a969c600-4ff1-4c58-be99-f2f09de50f92-0-0-eae92200-4353-440b-8123-217991f95a56"
  Warning  ProvisioningFailed    28s (x7 over 98s)   storage.cephfs.csi.ceph.com_csi-cephfsplugin-provisioner-6b5b5b49c5-f5t88_47b8f641-6a63-4d09-ad08-0359f1b6a9ee  failed to provision volume with StorageClass "ceph-filesystem": rpc error: code = Aborted desc = clone from snapshot is already in progress
  Normal   ExternalProvisioning  8s (x9 over 104s)   persistentvolume-controller                                                                                     Waiting for a volume to be created either by the external provisioner 'storage.cephfs.csi.ceph.com' or manually by the system administrator. If volume creation is delayed, please verify that the provisioner is running and correctly registered.

Logs

These errors keep coming out over and over again.
CSI-provisioner logs:

E0108 12:51:46.920488       1 controller.go:974] error syncing claim "e753bfee-ea1c-47af-bc73-2fd2e66576fb": failed to provision volume with StorageClass "ceph-filesystem": rpc error: code = Aborted desc = clone from snapshot is already in progress
I0108 12:51:46.920511       1 event.go:389] "Event occurred" object="rubrik-kupr/create-mn-k8s-snapshot-bdf4f0a5-0b7f-4572-977a-ff3ef1db402d-a969c600-4ff1-4c58-be99-f2f09de50f92-0-0-eae92200-4353-440b-8123-217991f95a56" fieldPath="" kind="PersistentVolumeClaim" apiVersion="v1" type="Warning" reason="ProvisioningFailed" message="failed to provision volume with StorageClass \"ceph-filesystem\": rpc error: code = Aborted desc = clone from snapshot is already in progress"

csi-cephfsplugin logs:

E0108 12:30:47.848741       1 omap.go:80] ID: 77 Req-ID: 0001-0007-storage-0000000000000001-56c9d391-0f05-4465-ae5f-b73cbc5bb949 omap not found (pool="ceph-filesystem-metadata", namespace="csi", name="csi.volume.56c9d391-0f05-4465-ae5f-b73cbc5bb949"): rados: ret=-2, No such file or directory
W0108 12:30:47.848803       1 voljournal.go:737] ID: 77 Req-ID: 0001-0007-storage-0000000000000001-56c9d391-0f05-4465-ae5f-b73cbc5bb949 unable to read omap keys: pool or key missing: key not found: rados: ret=-2, No such file or directory
E0108 12:30:47.862818       1 volume.go:164] ID: 77 Req-ID: 0001-0007-storage-0000000000000001-56c9d391-0f05-4465-ae5f-b73cbc5bb949 failed to get subvolume info for the vol csi-vol-56c9d391-0f05-4465-ae5f-b73cbc5bb949: rados: ret=-2, No such file or directory: "subvolume 'csi-vol-56c9d391-0f05-4465-ae5f-b73cbc5bb949' does not exist"
E0108 12:30:47.863001       1 controllerserver.go:529] ID: 77 Req-ID: 0001-0007-storage-0000000000000001-56c9d391-0f05-4465-ae5f-b73cbc5bb949 Error returned from newVolumeOptionsFromVolID: volume not found
E0108 12:47:19.229934       1 controllerserver.go:141] ID: 78 Req-ID: pvc-e753bfee-ea1c-47af-bc73-2fd2e66576fb failed to create clone from snapshot csi-snap-6a3144fa-0148-4f0c-89bc-d0a6c256fbc5: clone from snapshot is pending

The snapshots are being taken successfully and it's failing at copying content into the new pvc.
@sle78 sle78 changed the title Create a new PVC from snapshot fails Create a new cephfs PVC from snapshot fails Jan 8, 2025
@Madhu-1
Copy link
Collaborator

Madhu-1 commented Jan 9, 2025

@sle78 its not a failure, its a intermediate state

CephFS clones are full copies and the time to create a new PVC from snapshot or pvc-pvc clone depends on below 3 things

  • The size of the PVC
  • The amount of the data and number of small files in the pvc
  • Number of parallel clone operations are going on.

@sle78
Copy link
Author

sle78 commented Jan 9, 2025 •
edited
Loading

Hi @Madhu-1 thanks for your response. I waited for more than 24 hours and the clone never happened, it looks like it's failing to create the new subvolume?

This is a production clusters and in general we dont have any issue with creating ceph-block and ceph-filesystem devices, they're provisioned quite fast. This is only affecting cloning from snapshots, i.e. specifying the datasource in the PVC.
Again from the logs I can see that the snapshots are created fine too.

DataSource:
  APIGroup:  snapshot.storage.k8s.io
  Kind:      VolumeSnapshot
  Name:      data-fs-datasp58f

@Madhu-1
Copy link
Collaborator

Madhu-1 commented Jan 9, 2025

Yes this is expected as i mentioned above clones are full copy in cephfs. Please test below to ensure the cloning works and you might find similar issues already in the repo where people talked about this one

  • Create a PVC (don't write any data to it)
  • Create a snapshot
  • Create PVC from snapshot

Test the above flow to ensure the cephfs cloning works.

@sle78
Copy link
Author

sle78 commented Jan 9, 2025 •
edited
Loading

Right, all that worked fine:
kc get pvc

NAME         STATUS   VOLUME                                     CAPACITY   ACCESS MODES   STORAGECLASS      VOLUMEATTRIBUTESCLASS   AGE
csi-cloned   Bound    pvc-6012c72f-7ada-4d7c-9c39-d41977f40454   1Gi        RWX            ceph-filesystem   <unset>                 18s
csi-test     Bound    pvc-6b01b341-33d7-4b42-af06-82fb3907ce67   1Gi        RWX            ceph-filesystem   <unset>                 4m56s

kc get volumesnapshot csi-test-snapshot

NAME                READYTOUSE   SOURCEPVC   SOURCESNAPSHOTCONTENT   RESTORESIZE   SNAPSHOTCLASS     SNAPSHOTCONTENT                                    CREATIONTIME   AGE
csi-test-snapshot   true         csi-test                            1Gi           ceph-filesystem   snapcontent-5a7c1e3d-4af9-49c6-8974-ceeb84fd50ca   3m42s          3m43s

Where do I go from here?
The real clones that failed are 47GBi usage / 60GBi size, I appreciate that it takes some time but it should succeed eventually.

Thanks

@sle78
Copy link
Author

sle78 commented Jan 9, 2025 •
edited
Loading

Tried again using the failing PVC clone:
csi-cephfsplugin logs:

E0109 13:30:26.653202       1 omap.go:80] ID: 268 Req-ID: 0001-0007-storage-0000000000000001-1ec4bdc9-38d0-4299-9fb6-1bc28dfb9d84 omap not found (pool="ceph-filesystem-metadata", namespace="csi", name="csi.volume.1ec4bdc9-38d0-4299-9fb6-1bc28dfb9d84"): rados: ret=-2, No such file or directory
W0109 13:30:26.653260       1 voljournal.go:737] ID: 268 Req-ID: 0001-0007-storage-0000000000000001-1ec4bdc9-38d0-4299-9fb6-1bc28dfb9d84 unable to read omap keys: pool or key missing: key not found: rados: ret=-2, No such file or directory
E0109 13:30:26.659638       1 volume.go:164] ID: 268 Req-ID: 0001-0007-storage-0000000000000001-1ec4bdc9-38d0-4299-9fb6-1bc28dfb9d84 failed to get subvolume info for the vol csi-vol-1ec4bdc9-38d0-4299-9fb6-1bc28dfb9d84: rados: ret=-2, No such file or directory: "subvolume 'csi-vol-1ec4bdc9-38d0-4299-9fb6-1bc28dfb9d84' does not exist"
E0109 13:30:26.659817       1 controllerserver.go:529] ID: 268 Req-ID: 0001-0007-storage-0000000000000001-1ec4bdc9-38d0-4299-9fb6-1bc28dfb9d84 Error returned from newVolumeOptionsFromVolID: volume not found

I found some interesting logs on the ceph-mgr:
(cloner never terminates copying)

debug 2025-01-09T13:31:02.206+0000 7f1bdc6cc640  0 [volumes INFO volumes.fs.async_cloner] cloning to subvolume path: /volumes/csi/csi-vol-fe5ec2fc-59c2-440b-b9e0-1acc04726fda
debug 2025-01-09T13:31:02.206+0000 7f1bdc6cc640  0 [volumes INFO volumes.fs.async_cloner] starting clone: (ceph-filesystem, csi, csi-vol-fe5ec2fc-59c2-440b-b9e0-1acc04726fda)
debug 2025-01-09T13:31:02.242+0000 7f1bdc6cc640  0 [volumes INFO volumes.fs.async_cloner] Delayed cloning (ceph-filesystem, csi, csi-vol-fe5ec2fc-59c2-440b-b9e0-1acc04726fda) -- by 0 seconds
debug 2025-01-09T13:31:04.926+0000 7f1bdc6cc640  0 [volumes INFO volumes.fs.async_cloner] copying data from b'/volumes/csi/csi-vol-a015011c-3b84-4699-9213-1e314fb58515/.snap/csi-snap-9d3e0d41-2944-4c68-856f-6f8de076ae9a/8f887514-63da-4055-8098-b16642835dd7' to b'/volumes/csi/csi-vol-fe5ec2fc-59c2-440b-b9e0-1acc04726fda/bfe1d44c-b40d-4508-9f0b-5eee8d5152aa'

debug 2025-01-09T13:28:00.532+0000 7f1bff251640  0 log_channel(audit) log [DBG] : from='client.65021579 -' entity='client.csi-cephfs-provisioner' cmd=[{"prefix":"fs subvolume create","format":"json","vol_name":"ceph-filesystem","group_name":"csi","sub_name":"csi-vol-1ec4bdc9-38d0-4299-9fb6-1bc28dfb9d84","size":64424509440,"pool_layout":"ceph-filesystem-data0","namespace_isolated":false}]: dispatch
debug 2025-01-09T13:28:00.532+0000 7f1bd56be640  0 [volumes INFO volumes.module] Starting _cmd_fs_subvolume_create(format:json, group_name:csi, namespace_isolated:False, pool_layout:ceph-filesystem-data0, prefix:fs subvolume create, size:64424509440, sub_name:csi-vol-1ec4bdc9-38d0-4299-9fb6-1bc28dfb9d84, vol_name:ceph-filesystem) < ""
debug 2025-01-09T13:28:00.596+0000 7f1bd56be640  0 [volumes INFO volumes.fs.operations.versions.metadata_manager] wrote 158 bytes to config b'/volumes/csi/csi-vol-1ec4bdc9-38d0-4299-9fb6-1bc28dfb9d84/.meta.tmp'
debug 2025-01-09T13:28:00.596+0000 7f1bd56be640  0 [volumes INFO volumes.fs.operations.versions.metadata_manager] Renamed b'/volumes/csi/csi-vol-1ec4bdc9-38d0-4299-9fb6-1bc28dfb9d84/.meta.tmp' to config b'/volumes/csi/csi-vol-1ec4bdc9-38d0-4299-9fb6-1bc28dfb9d84/.meta'
debug 2025-01-09T13:28:00.600+0000 7f1bd56be640  0 [volumes INFO volumes.module] Finishing _cmd_fs_subvolume_create(format:json, group_name:csi, namespace_isolated:False, pool_layout:ceph-filesystem-data0, prefix:fs subvolume create, size:64424509440, sub_name:csi-vol-1ec4bdc9-38d0-4299-9fb6-1bc28dfb9d84, vol_name:ceph-filesystem) < ""
debug 2025-01-09T13:28:00.604+0000 7f1bff251640  0 log_channel(audit) log [DBG] : from='client.65021579 -' entity='client.csi-cephfs-provisioner' cmd=[{"group_name":"csi","prefix":"fs subvolume getpath","sub_name":"csi-vol-1ec4bdc9-38d0-4299-9fb6-1bc28dfb9d84","vol_name":"ceph-filesystem"}]: dispatch
debug 2025-01-09T13:28:00.604+0000 7f1bd56be640  0 [volumes INFO volumes.module] Starting _cmd_fs_subvolume_getpath(group_name:csi, prefix:fs subvolume getpath, sub_name:csi-vol-1ec4bdc9-38d0-4299-9fb6-1bc28dfb9d84, vol_name:ceph-filesystem) < ""
debug 2025-01-09T13:28:00.612+0000 7f1bd56be640  0 [volumes INFO volumes.module] Finishing _cmd_fs_subvolume_getpath(group_name:csi, prefix:fs subvolume getpath, sub_name:csi-vol-1ec4bdc9-38d0-4299-9fb6-1bc28dfb9d84, vol_name:ceph-filesystem) < ""
debug 2025-01-09T13:30:26.302+0000 7f1bff251640  0 log_channel(audit) log [DBG] : from='client.65021579 -' entity='client.csi-cephfs-provisioner' cmd=[{"format":"json","group_name":"csi","prefix":"fs subvolume info","sub_name":"csi-vol-1ec4bdc9-38d0-4299-9fb6-1bc28dfb9d84","vol_name":"ceph-filesystem"}]: dispatch
debug 2025-01-09T13:30:26.302+0000 7f1bd56be640  0 [volumes INFO volumes.module] Starting _cmd_fs_subvolume_info(format:json, group_name:csi, prefix:fs subvolume info, sub_name:csi-vol-1ec4bdc9-38d0-4299-9fb6-1bc28dfb9d84, vol_name:ceph-filesystem) < ""
debug 2025-01-09T13:30:26.542+0000 7f1bd56be640  0 [volumes INFO volumes.module] Finishing _cmd_fs_subvolume_info(format:json, group_name:csi, prefix:fs subvolume info, sub_name:csi-vol-1ec4bdc9-38d0-4299-9fb6-1bc28dfb9d84, vol_name:ceph-filesystem) < ""
debug 2025-01-09T13:30:26.546+0000 7f1bff251640  0 log_channel(audit) log [DBG] : from='client.65021579 -' entity='client.csi-cephfs-provisioner' cmd=[{"format":"json","group_name":"csi","prefix":"fs subvolume rm","retain_snapshots":true,"sub_name":"csi-vol-1ec4bdc9-38d0-4299-9fb6-1bc28dfb9d84","vol_name":"ceph-filesystem"}]: dispatch
debug 2025-01-09T13:30:26.546+0000 7f1bd56be640  0 [volumes INFO volumes.module] Starting _cmd_fs_subvolume_rm(format:json, group_name:csi, prefix:fs subvolume rm, retain_snapshots:True, sub_name:csi-vol-1ec4bdc9-38d0-4299-9fb6-1bc28dfb9d84, vol_name:ceph-filesystem) < ""
debug 2025-01-09T13:30:26.558+0000 7f1bd56be640  0 [volumes INFO volumes.fs.operations.versions.subvolume_base] subvolume path 'b'/volumes/csi/csi-vol-1ec4bdc9-38d0-4299-9fb6-1bc28dfb9d84'' moved to trashcan
debug 2025-01-09T13:30:26.558+0000 7f1bd56be640  0 [volumes INFO volumes.module] Finishing _cmd_fs_subvolume_rm(format:json, group_name:csi, prefix:fs subvolume rm, retain_snapshots:True, sub_name:csi-vol-1ec4bdc9-38d0-4299-9fb6-1bc28dfb9d84, vol_name:ceph-filesystem) < ""
debug 2025-01-09T13:30:26.614+0000 7f1bff251640  0 log_channel(audit) log [DBG] : from='client.65021579 -' entity='client.csi-cephfs-provisioner' cmd=[{"format":"json","group_name":"csi","prefix":"fs subvolume info","sub_name":"csi-vol-1ec4bdc9-38d0-4299-9fb6-1bc28dfb9d84","vol_name":"ceph-filesystem"}]: dispatch
debug 2025-01-09T13:30:26.614+0000 7f1bd56be640  0 [volumes INFO volumes.module] Starting _cmd_fs_subvolume_info(format:json, group_name:csi, prefix:fs subvolume info, sub_name:csi-vol-1ec4bdc9-38d0-4299-9fb6-1bc28dfb9d84, vol_name:ceph-filesystem) < ""
debug 2025-01-09T13:30:26.618+0000 7f1bd56be640  0 [volumes INFO volumes.module] Finishing _cmd_fs_subvolume_info(format:json, group_name:csi, prefix:fs subvolume info, sub_name:csi-vol-1ec4bdc9-38d0-4299-9fb6-1bc28dfb9d84, vol_name:ceph-filesystem) < ""
debug 2025-01-09T13:30:26.618+0000 7f1bd56be640 -1 mgr.server reply reply (2) No such file or directory subvolume 'csi-vol-1ec4bdc9-38d0-4299-9fb6-1bc28dfb9d84' does not exist

Note this in the ceph mgr logs:

debug 2025-01-09T13:30:26.558+0000 7f1bd56be640  0 [volumes INFO volumes.fs.operations.versions.subvolume_base] subvolume path 'b'/volumes/csi/csi-vol-1ec4bdc9-38d0-4299-9fb6-1bc28dfb9d84'' moved to trashcan

@nixpanic nixpanic added the component/cephfs Issues related to CephFS label Jan 9, 2025
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
component/cephfs Issues related to CephFS
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@nixpanic @Madhu-1 @sle78