ceph fs (meta) data inconsistent
Dear fellow cephers, today we observed a somewhat worrisome inconsistency on our ceph fs. A file created on one host showed up as 0 length on all other hosts: [user1@host1 h2lib]$ ls -lh total 37M -rw-rw---- 1 user1 user1 12K Nov 1 11:59 dll_wrapper.py [user2@host2 h2lib]# ls -l total 34 -rw-rw----. 1 user1 user1 0 Nov 1 11:59 dll_wrapper.py [user1@host1 h2lib]$ cp dll_wrapper.py dll_wrapper.py.test [user1@host1 h2lib]$ ls -l total 37199 -rw-rw---- 1 user1 user1 11641 Nov 1 11:59 dll_wrapper.py -rw-rw---- 1 user1 user1 11641 Nov 1 13:10 dll_wrapper.py.test [user2@host2 h2lib]# ls -l total 45 -rw-rw----. 1 user1 user1 0 Nov 1 11:59 dll_wrapper.py -rw-rw----. 1 user1 user1 11641 Nov 1 13:10 dll_wrapper.py.test Executing a sync on all these hosts did not help. However, deleting the problematic file and replacing it with a copy seemed to work around the issue. We saw this with ceph kclients of different versions, it seems to be on the MDS side. How can this happen and how dangerous is it? ceph fs status (showing ceph version): # ceph fs status con-fs2 - 1662 clients ======= RANK STATE MDS ACTIVITY DNS INOS 0 active ceph-15 Reqs: 14 /s 2307k 2278k 1 active ceph-11 Reqs: 159 /s 4208k 4203k 2 active ceph-17 Reqs: 3 /s 4533k 4501k 3 active ceph-24 Reqs: 3 /s 4593k 4300k 4 active ceph-14 Reqs: 1 /s 4228k 4226k 5 active ceph-13 Reqs: 5 /s 1994k 1782k 6 active ceph-16 Reqs: 8 /s 5022k 4841k 7 active ceph-23 Reqs: 9 /s 4140k 4116k POOL TYPE USED AVAIL con-fs2-meta1 metadata 2177G 7085G con-fs2-meta2 data 0 7085G con-fs2-data data 1242T 4233T con-fs2-data-ec-ssd data 706G 22.1T con-fs2-data2 data 3409T 3848T STANDBY MDS ceph-10 ceph-08 ceph-09 ceph-12 MDS version: ceph version 15.2.17 (8a82819d84cf884bd39c17e3236e0632ac146dc4) octopus (stable) There is no health issue: # ceph status cluster: id: abc health: HEALTH_WARN 3 pgs not deep-scrubbed in time services: mon: 5 daemons, quorum ceph-01,ceph-02,ceph-03,ceph-25,ceph-26 (age 9w) mgr: ceph-25(active, since 7w), standbys: ceph-26, ceph-01, ceph-03, ceph-02 mds: con-fs2:8 4 up:standby 8 up:active osd: 1284 osds: 1279 up (since 2d), 1279 in (since 5d) task status: data: pools: 14 pools, 25065 pgs objects: 2.20G objects, 3.9 PiB usage: 4.9 PiB used, 8.2 PiB / 13 PiB avail pgs: 25039 active+clean 26 active+clean+scrubbing+deep io: client: 799 MiB/s rd, 55 MiB/s wr, 3.12k op/s rd, 1.82k op/s wr The inconsistency seems undiagnosed, I couldn't find anything interesting in the cluster log. What should I look for and where? I moved the folder to another location for diagnosis. Unfortunately, I don't have 2 clients any more showing different numbers, I see a 0 length now everywhere for the moved folder. I'm pretty sure though that the file still is non-zero length. Thanks for any pointers. ================= Frank Schilder AIT Risø Campus Bygning 109, rum S14
We have seen issues like this a few times and they have all been kernel client bugs with CephFS’ internal “capability” file locking protocol. I’m not aware of any extant bugs like this in our code base, but kernel patches can take a long and winding path before they end up on deployed systems. Most likely, if you were to restart some combination of the client which wrote the file and the client(s) reading it, the size would propagate correctly. As long as you’ve synced the data, it’s definitely present in the cluster. Adding Xiubo, who has worked on these and may have other comments. -Greg On Wed, Nov 1, 2023 at 7:16 AM Frank Schilder <frans@dtu.dk> wrote:
Dear fellow cephers,
today we observed a somewhat worrisome inconsistency on our ceph fs. A file created on one host showed up as 0 length on all other hosts:
[user1@host1 h2lib]$ ls -lh total 37M -rw-rw---- 1 user1 user1 12K Nov 1 11:59 dll_wrapper.py
[user2@host2 h2lib]# ls -l total 34 -rw-rw----. 1 user1 user1 0 Nov 1 11:59 dll_wrapper.py
[user1@host1 h2lib]$ cp dll_wrapper.py dll_wrapper.py.test [user1@host1 h2lib]$ ls -l total 37199 -rw-rw---- 1 user1 user1 11641 Nov 1 11:59 dll_wrapper.py -rw-rw---- 1 user1 user1 11641 Nov 1 13:10 dll_wrapper.py.test
[user2@host2 h2lib]# ls -l total 45 -rw-rw----. 1 user1 user1 0 Nov 1 11:59 dll_wrapper.py -rw-rw----. 1 user1 user1 11641 Nov 1 13:10 dll_wrapper.py.test
Executing a sync on all these hosts did not help. However, deleting the problematic file and replacing it with a copy seemed to work around the issue. We saw this with ceph kclients of different versions, it seems to be on the MDS side.
How can this happen and how dangerous is it?
ceph fs status (showing ceph version):
# ceph fs status con-fs2 - 1662 clients ======= RANK STATE MDS ACTIVITY DNS INOS 0 active ceph-15 Reqs: 14 /s 2307k 2278k 1 active ceph-11 Reqs: 159 /s 4208k 4203k 2 active ceph-17 Reqs: 3 /s 4533k 4501k 3 active ceph-24 Reqs: 3 /s 4593k 4300k 4 active ceph-14 Reqs: 1 /s 4228k 4226k 5 active ceph-13 Reqs: 5 /s 1994k 1782k 6 active ceph-16 Reqs: 8 /s 5022k 4841k 7 active ceph-23 Reqs: 9 /s 4140k 4116k POOL TYPE USED AVAIL con-fs2-meta1 metadata 2177G 7085G con-fs2-meta2 data 0 7085G con-fs2-data data 1242T 4233T con-fs2-data-ec-ssd data 706G 22.1T con-fs2-data2 data 3409T 3848T STANDBY MDS ceph-10 ceph-08 ceph-09 ceph-12 MDS version: ceph version 15.2.17 (8a82819d84cf884bd39c17e3236e0632ac146dc4) octopus (stable)
There is no health issue:
# ceph status cluster: id: abc health: HEALTH_WARN 3 pgs not deep-scrubbed in time
services: mon: 5 daemons, quorum ceph-01,ceph-02,ceph-03,ceph-25,ceph-26 (age 9w) mgr: ceph-25(active, since 7w), standbys: ceph-26, ceph-01, ceph-03, ceph-02 mds: con-fs2:8 4 up:standby 8 up:active osd: 1284 osds: 1279 up (since 2d), 1279 in (since 5d)
task status:
data: pools: 14 pools, 25065 pgs objects: 2.20G objects, 3.9 PiB usage: 4.9 PiB used, 8.2 PiB / 13 PiB avail pgs: 25039 active+clean 26 active+clean+scrubbing+deep
io: client: 799 MiB/s rd, 55 MiB/s wr, 3.12k op/s rd, 1.82k op/s wr
The inconsistency seems undiagnosed, I couldn't find anything interesting in the cluster log. What should I look for and where?
I moved the folder to another location for diagnosis. Unfortunately, I don't have 2 clients any more showing different numbers, I see a 0 length now everywhere for the moved folder. I'm pretty sure though that the file still is non-zero length.
Thanks for any pointers. ================= Frank Schilder AIT Risø Campus Bygning 109, rum S14 _______________________________________________ ceph-users mailing list -- ceph-users@ceph.io To unsubscribe send an email to ceph-users-leave@ceph.io
Hi all, the problem re-appeared in the following way. After moving the problematic folder out and copying it back, all files showed the correct sizes. Today, we observe that the issue is back in the copy that was fine yesterday: [user1@host11 h2lib]$ ls -l total 37198 -rw-rw---- 1 user1 user1 11641 Nov 2 11:32 dll_wrapper.py [user2@host2 h2lib]# ls -l total 44 -rw-rw----. 1 user1 user1 0 Nov 2 11:28 dll_wrapper.py It is correct in the snapshot though: [user2@host2 h2lib]# cd .snap [user2@host2 .snap]# ls _2023-11-02_000611+0100_daily_1 [user2@host2 .snap]# cd _2023-11-02_000611+0100_daily_1/ [user2@host2 _2023-11-02_000611+0100_daily_1]# ls -l total 37188 -rw-rw----. 1 user1 user1 11641 Nov 1 13:30 dll_wrapper.py It seems related to the path, bot the inode number. Could the re-appearance of the 0 length have been triggered by taking the snapshot? We plan to reboot later today the server where the file was written. Until hen we can do diagnostics while the issue is visible. Please let us know what information we can provide. Best regards, ================= Frank Schilder AIT Risø Campus Bygning 109, rum S14 ________________________________________ From: Gregory Farnum <gfarnum@redhat.com> Sent: Wednesday, November 1, 2023 4:57 PM To: Frank Schilder; Xiubo Li Cc: ceph-users@ceph.io Subject: Re: [ceph-users] ceph fs (meta) data inconsistent We have seen issues like this a few times and they have all been kernel client bugs with CephFS’ internal “capability” file locking protocol. I’m not aware of any extant bugs like this in our code base, but kernel patches can take a long and winding path before they end up on deployed systems. Most likely, if you were to restart some combination of the client which wrote the file and the client(s) reading it, the size would propagate correctly. As long as you’ve synced the data, it’s definitely present in the cluster. Adding Xiubo, who has worked on these and may have other comments. -Greg On Wed, Nov 1, 2023 at 7:16 AM Frank Schilder <frans@dtu.dk<mailto:frans@dtu.dk>> wrote: Dear fellow cephers, today we observed a somewhat worrisome inconsistency on our ceph fs. A file created on one host showed up as 0 length on all other hosts: [user1@host1 h2lib]$ ls -lh total 37M -rw-rw---- 1 user1 user1 12K Nov 1 11:59 dll_wrapper.py [user2@host2 h2lib]# ls -l total 34 -rw-rw----. 1 user1 user1 0 Nov 1 11:59 dll_wrapper.py [user1@host1 h2lib]$ cp dll_wrapper.py dll_wrapper.py.test [user1@host1 h2lib]$ ls -l total 37199 -rw-rw---- 1 user1 user1 11641 Nov 1 11:59 dll_wrapper.py -rw-rw---- 1 user1 user1 11641 Nov 1 13:10 dll_wrapper.py.test [user2@host2 h2lib]# ls -l total 45 -rw-rw----. 1 user1 user1 0 Nov 1 11:59 dll_wrapper.py -rw-rw----. 1 user1 user1 11641 Nov 1 13:10 dll_wrapper.py.test Executing a sync on all these hosts did not help. However, deleting the problematic file and replacing it with a copy seemed to work around the issue. We saw this with ceph kclients of different versions, it seems to be on the MDS side. How can this happen and how dangerous is it? ceph fs status (showing ceph version): # ceph fs status con-fs2 - 1662 clients ======= RANK STATE MDS ACTIVITY DNS INOS 0 active ceph-15 Reqs: 14 /s 2307k 2278k 1 active ceph-11 Reqs: 159 /s 4208k 4203k 2 active ceph-17 Reqs: 3 /s 4533k 4501k 3 active ceph-24 Reqs: 3 /s 4593k 4300k 4 active ceph-14 Reqs: 1 /s 4228k 4226k 5 active ceph-13 Reqs: 5 /s 1994k 1782k 6 active ceph-16 Reqs: 8 /s 5022k 4841k 7 active ceph-23 Reqs: 9 /s 4140k 4116k POOL TYPE USED AVAIL con-fs2-meta1 metadata 2177G 7085G con-fs2-meta2 data 0 7085G con-fs2-data data 1242T 4233T con-fs2-data-ec-ssd data 706G 22.1T con-fs2-data2 data 3409T 3848T STANDBY MDS ceph-10 ceph-08 ceph-09 ceph-12 MDS version: ceph version 15.2.17 (8a82819d84cf884bd39c17e3236e0632ac146dc4) octopus (stable) There is no health issue: # ceph status cluster: id: abc health: HEALTH_WARN 3 pgs not deep-scrubbed in time services: mon: 5 daemons, quorum ceph-01,ceph-02,ceph-03,ceph-25,ceph-26 (age 9w) mgr: ceph-25(active, since 7w), standbys: ceph-26, ceph-01, ceph-03, ceph-02 mds: con-fs2:8 4 up:standby 8 up:active osd: 1284 osds: 1279 up (since 2d), 1279 in (since 5d) task status: data: pools: 14 pools, 25065 pgs objects: 2.20G objects, 3.9 PiB usage: 4.9 PiB used, 8.2 PiB / 13 PiB avail pgs: 25039 active+clean 26 active+clean+scrubbing+deep io: client: 799 MiB/s rd, 55 MiB/s wr, 3.12k op/s rd, 1.82k op/s wr The inconsistency seems undiagnosed, I couldn't find anything interesting in the cluster log. What should I look for and where? I moved the folder to another location for diagnosis. Unfortunately, I don't have 2 clients any more showing different numbers, I see a 0 length now everywhere for the moved folder. I'm pretty sure though that the file still is non-zero length. Thanks for any pointers. ================= Frank Schilder AIT Risø Campus Bygning 109, rum S14 _______________________________________________ ceph-users mailing list -- ceph-users@ceph.io<mailto:ceph-users@ceph.io> To unsubscribe send an email to ceph-users-leave@ceph.io<mailto:ceph-users-leave@ceph.io>
Hi Gregory and Xiubo, we have a smoking gun. The error shows up when using python's shutil.copy function. It affects newer versions of python3. Here some test results (quoted e-mail from our user):
I now have a minimal example that reproduces the error:
echo test > myfile.txt ml Python/3.10.4-GCCcore-11.3.0-bare python -c "import shutil; shutil.copy('myfile.txt','myfile2.txt')" ls -l | grep myfile srun --partition fatq --time 01:00:00 --nodes 1 --exclusive --pty bash ls -l | grep myfile
The problem occurs when I copy a file via python (Python/3.10.4-GCCcore-11.3.0-bare) The problems does not occur when running the script with the default python
[user1@host1 ~]$ echo test > myfile.txt [user1@host1 ~]$ ml Python/3.10.4-GCCcore-11.3.0-bare [user1@host1 ~]$ python -c "import shutil; shutil.copy('myfile.txt','myfile2.txt')" [user1@host1 ~]$ ls -l | grep myfile -rw-rw---- 1 user1 user1 5 Nov 3 07:23 myfile2.txt -rw-rw---- 1 user1 user1 5 Nov 3 07:23 myfile.txt [user1@host1 ~]$ srun --partition fatq --time 01:00:00 --nodes 1 --exclusive --pty bash [user1@host3 ~]$ ls -l | grep myfile -rw-rw---- 1 user1 user1 0 Nov 3 07:23 myfile2.txt -rw-rw---- 1 user1 user1 5 Nov 3 07:23 myfile.txt
Just tried with some other python versions
Ok Python/3.6.4-intel-2018a Python/3.7.4-GCCcore-8.3.0
Fail Python/3.8.2-GCCcore-9.3.0 Python/3.9.5-GCCcore-10.3.0-bare Python/3.9.5-GCCcore-10.3.0 Python/3.10.4-GCCcore-11.3.0-bare Python/3.10.4-GCCcore-11.3.0 Python/3.10.8-GCCcore-12.2.0-bare
These are easybuild python modules using different gcc versions to build. The default version of python referred to is Python 2.7.5. Is this a known problem with python3 and is there a patch we can apply? I wonder how python manages to break the file system so consistently. Thanks and best regards, ================= Frank Schilder AIT Risø Campus Bygning 109, rum S14 ________________________________________ From: Frank Schilder <frans@dtu.dk> Sent: Thursday, November 2, 2023 12:12 PM To: Gregory Farnum; Xiubo Li Cc: ceph-users@ceph.io Subject: [ceph-users] Re: ceph fs (meta) data inconsistent Hi all, the problem re-appeared in the following way. After moving the problematic folder out and copying it back, all files showed the correct sizes. Today, we observe that the issue is back in the copy that was fine yesterday: [user1@host11 h2lib]$ ls -l total 37198 -rw-rw---- 1 user1 user1 11641 Nov 2 11:32 dll_wrapper.py [user2@host2 h2lib]# ls -l total 44 -rw-rw----. 1 user1 user1 0 Nov 2 11:28 dll_wrapper.py It is correct in the snapshot though: [user2@host2 h2lib]# cd .snap [user2@host2 .snap]# ls _2023-11-02_000611+0100_daily_1 [user2@host2 .snap]# cd _2023-11-02_000611+0100_daily_1/ [user2@host2 _2023-11-02_000611+0100_daily_1]# ls -l total 37188 -rw-rw----. 1 user1 user1 11641 Nov 1 13:30 dll_wrapper.py It seems related to the path, bot the inode number. Could the re-appearance of the 0 length have been triggered by taking the snapshot? We plan to reboot later today the server where the file was written. Until hen we can do diagnostics while the issue is visible. Please let us know what information we can provide. Best regards, ================= Frank Schilder AIT Risø Campus Bygning 109, rum S14 ________________________________________ From: Gregory Farnum <gfarnum@redhat.com> Sent: Wednesday, November 1, 2023 4:57 PM To: Frank Schilder; Xiubo Li Cc: ceph-users@ceph.io Subject: Re: [ceph-users] ceph fs (meta) data inconsistent We have seen issues like this a few times and they have all been kernel client bugs with CephFS’ internal “capability” file locking protocol. I’m not aware of any extant bugs like this in our code base, but kernel patches can take a long and winding path before they end up on deployed systems. Most likely, if you were to restart some combination of the client which wrote the file and the client(s) reading it, the size would propagate correctly. As long as you’ve synced the data, it’s definitely present in the cluster. Adding Xiubo, who has worked on these and may have other comments. -Greg On Wed, Nov 1, 2023 at 7:16 AM Frank Schilder <frans@dtu.dk<mailto:frans@dtu.dk>> wrote: Dear fellow cephers, today we observed a somewhat worrisome inconsistency on our ceph fs. A file created on one host showed up as 0 length on all other hosts: [user1@host1 h2lib]$ ls -lh total 37M -rw-rw---- 1 user1 user1 12K Nov 1 11:59 dll_wrapper.py [user2@host2 h2lib]# ls -l total 34 -rw-rw----. 1 user1 user1 0 Nov 1 11:59 dll_wrapper.py [user1@host1 h2lib]$ cp dll_wrapper.py dll_wrapper.py.test [user1@host1 h2lib]$ ls -l total 37199 -rw-rw---- 1 user1 user1 11641 Nov 1 11:59 dll_wrapper.py -rw-rw---- 1 user1 user1 11641 Nov 1 13:10 dll_wrapper.py.test [user2@host2 h2lib]# ls -l total 45 -rw-rw----. 1 user1 user1 0 Nov 1 11:59 dll_wrapper.py -rw-rw----. 1 user1 user1 11641 Nov 1 13:10 dll_wrapper.py.test Executing a sync on all these hosts did not help. However, deleting the problematic file and replacing it with a copy seemed to work around the issue. We saw this with ceph kclients of different versions, it seems to be on the MDS side. How can this happen and how dangerous is it? ceph fs status (showing ceph version): # ceph fs status con-fs2 - 1662 clients ======= RANK STATE MDS ACTIVITY DNS INOS 0 active ceph-15 Reqs: 14 /s 2307k 2278k 1 active ceph-11 Reqs: 159 /s 4208k 4203k 2 active ceph-17 Reqs: 3 /s 4533k 4501k 3 active ceph-24 Reqs: 3 /s 4593k 4300k 4 active ceph-14 Reqs: 1 /s 4228k 4226k 5 active ceph-13 Reqs: 5 /s 1994k 1782k 6 active ceph-16 Reqs: 8 /s 5022k 4841k 7 active ceph-23 Reqs: 9 /s 4140k 4116k POOL TYPE USED AVAIL con-fs2-meta1 metadata 2177G 7085G con-fs2-meta2 data 0 7085G con-fs2-data data 1242T 4233T con-fs2-data-ec-ssd data 706G 22.1T con-fs2-data2 data 3409T 3848T STANDBY MDS ceph-10 ceph-08 ceph-09 ceph-12 MDS version: ceph version 15.2.17 (8a82819d84cf884bd39c17e3236e0632ac146dc4) octopus (stable) There is no health issue: # ceph status cluster: id: abc health: HEALTH_WARN 3 pgs not deep-scrubbed in time services: mon: 5 daemons, quorum ceph-01,ceph-02,ceph-03,ceph-25,ceph-26 (age 9w) mgr: ceph-25(active, since 7w), standbys: ceph-26, ceph-01, ceph-03, ceph-02 mds: con-fs2:8 4 up:standby 8 up:active osd: 1284 osds: 1279 up (since 2d), 1279 in (since 5d) task status: data: pools: 14 pools, 25065 pgs objects: 2.20G objects, 3.9 PiB usage: 4.9 PiB used, 8.2 PiB / 13 PiB avail pgs: 25039 active+clean 26 active+clean+scrubbing+deep io: client: 799 MiB/s rd, 55 MiB/s wr, 3.12k op/s rd, 1.82k op/s wr The inconsistency seems undiagnosed, I couldn't find anything interesting in the cluster log. What should I look for and where? I moved the folder to another location for diagnosis. Unfortunately, I don't have 2 clients any more showing different numbers, I see a 0 length now everywhere for the moved folder. I'm pretty sure though that the file still is non-zero length. Thanks for any pointers. ================= Frank Schilder AIT Risø Campus Bygning 109, rum S14 _______________________________________________ ceph-users mailing list -- ceph-users@ceph.io<mailto:ceph-users@ceph.io> To unsubscribe send an email to ceph-users-leave@ceph.io<mailto:ceph-users-leave@ceph.io> _______________________________________________ ceph-users mailing list -- ceph-users@ceph.io To unsubscribe send an email to ceph-users-leave@ceph.io
On 11/3/23 16:43, Frank Schilder wrote:
Hi Gregory and Xiubo,
we have a smoking gun. The error shows up when using python's shutil.copy function. It affects newer versions of python3. Here some test results (quoted e-mail from our user):
I now have a minimal example that reproduces the error:
echo test > myfile.txt ml Python/3.10.4-GCCcore-11.3.0-bare python -c "import shutil; shutil.copy('myfile.txt','myfile2.txt')" ls -l | grep myfile srun --partition fatq --time 01:00:00 --nodes 1 --exclusive --pty bash ls -l | grep myfile
The problem occurs when I copy a file via python (Python/3.10.4-GCCcore-11.3.0-bare) The problems does not occur when running the script with the default python
[user1@host1 ~]$ echo test > myfile.txt [user1@host1 ~]$ ml Python/3.10.4-GCCcore-11.3.0-bare [user1@host1 ~]$ python -c "import shutil; shutil.copy('myfile.txt','myfile2.txt')" [user1@host1 ~]$ ls -l | grep myfile -rw-rw---- 1 user1 user1 5 Nov 3 07:23 myfile2.txt -rw-rw---- 1 user1 user1 5 Nov 3 07:23 myfile.txt [user1@host1 ~]$ srun --partition fatq --time 01:00:00 --nodes 1 --exclusive --pty bash [user1@host3 ~]$ ls -l | grep myfile -rw-rw---- 1 user1 user1 0 Nov 3 07:23 myfile2.txt -rw-rw---- 1 user1 user1 5 Nov 3 07:23 myfile.txt
It looks like the cap update request was dropped to the ground in MDS.
Just tried with some other python versions
Ok Python/3.6.4-intel-2018a Python/3.7.4-GCCcore-8.3.0
Fail Python/3.8.2-GCCcore-9.3.0 Python/3.9.5-GCCcore-10.3.0-bare Python/3.9.5-GCCcore-10.3.0 Python/3.10.4-GCCcore-11.3.0-bare Python/3.10.4-GCCcore-11.3.0 Python/3.10.8-GCCcore-12.2.0-bare These are easybuild python modules using different gcc versions to build. The default version of python referred to is Python 2.7.5. Is this a known problem with python3 and is there a patch we can apply? I wonder how python manages to break the file system so consistently.
If you can reproduce it, then please provide the mds logs by setting: debug mds = 25 debug ms = 1 Thanks - Xiubo
Thanks and best regards, ================= Frank Schilder AIT Risø Campus Bygning 109, rum S14
________________________________________ From: Frank Schilder <frans@dtu.dk> Sent: Thursday, November 2, 2023 12:12 PM To: Gregory Farnum; Xiubo Li Cc: ceph-users@ceph.io Subject: [ceph-users] Re: ceph fs (meta) data inconsistent
Hi all,
the problem re-appeared in the following way. After moving the problematic folder out and copying it back, all files showed the correct sizes. Today, we observe that the issue is back in the copy that was fine yesterday:
[user1@host11 h2lib]$ ls -l total 37198 -rw-rw---- 1 user1 user1 11641 Nov 2 11:32 dll_wrapper.py
[user2@host2 h2lib]# ls -l total 44 -rw-rw----. 1 user1 user1 0 Nov 2 11:28 dll_wrapper.py
It is correct in the snapshot though:
[user2@host2 h2lib]# cd .snap [user2@host2 .snap]# ls _2023-11-02_000611+0100_daily_1 [user2@host2 .snap]# cd _2023-11-02_000611+0100_daily_1/ [user2@host2 _2023-11-02_000611+0100_daily_1]# ls -l total 37188 -rw-rw----. 1 user1 user1 11641 Nov 1 13:30 dll_wrapper.py
It seems related to the path, bot the inode number. Could the re-appearance of the 0 length have been triggered by taking the snapshot?
We plan to reboot later today the server where the file was written. Until hen we can do diagnostics while the issue is visible. Please let us know what information we can provide.
Best regards, ================= Frank Schilder AIT Risø Campus Bygning 109, rum S14
________________________________________ From: Gregory Farnum <gfarnum@redhat.com> Sent: Wednesday, November 1, 2023 4:57 PM To: Frank Schilder; Xiubo Li Cc: ceph-users@ceph.io Subject: Re: [ceph-users] ceph fs (meta) data inconsistent
We have seen issues like this a few times and they have all been kernel client bugs with CephFS’ internal “capability” file locking protocol. I’m not aware of any extant bugs like this in our code base, but kernel patches can take a long and winding path before they end up on deployed systems.
Most likely, if you were to restart some combination of the client which wrote the file and the client(s) reading it, the size would propagate correctly. As long as you’ve synced the data, it’s definitely present in the cluster.
Adding Xiubo, who has worked on these and may have other comments. -Greg
On Wed, Nov 1, 2023 at 7:16 AM Frank Schilder <frans@dtu.dk<mailto:frans@dtu.dk>> wrote: Dear fellow cephers,
today we observed a somewhat worrisome inconsistency on our ceph fs. A file created on one host showed up as 0 length on all other hosts:
[user1@host1 h2lib]$ ls -lh total 37M -rw-rw---- 1 user1 user1 12K Nov 1 11:59 dll_wrapper.py
[user2@host2 h2lib]# ls -l total 34 -rw-rw----. 1 user1 user1 0 Nov 1 11:59 dll_wrapper.py
[user1@host1 h2lib]$ cp dll_wrapper.py dll_wrapper.py.test [user1@host1 h2lib]$ ls -l total 37199 -rw-rw---- 1 user1 user1 11641 Nov 1 11:59 dll_wrapper.py -rw-rw---- 1 user1 user1 11641 Nov 1 13:10 dll_wrapper.py.test
[user2@host2 h2lib]# ls -l total 45 -rw-rw----. 1 user1 user1 0 Nov 1 11:59 dll_wrapper.py -rw-rw----. 1 user1 user1 11641 Nov 1 13:10 dll_wrapper.py.test
Executing a sync on all these hosts did not help. However, deleting the problematic file and replacing it with a copy seemed to work around the issue. We saw this with ceph kclients of different versions, it seems to be on the MDS side.
How can this happen and how dangerous is it?
ceph fs status (showing ceph version):
# ceph fs status con-fs2 - 1662 clients ======= RANK STATE MDS ACTIVITY DNS INOS 0 active ceph-15 Reqs: 14 /s 2307k 2278k 1 active ceph-11 Reqs: 159 /s 4208k 4203k 2 active ceph-17 Reqs: 3 /s 4533k 4501k 3 active ceph-24 Reqs: 3 /s 4593k 4300k 4 active ceph-14 Reqs: 1 /s 4228k 4226k 5 active ceph-13 Reqs: 5 /s 1994k 1782k 6 active ceph-16 Reqs: 8 /s 5022k 4841k 7 active ceph-23 Reqs: 9 /s 4140k 4116k POOL TYPE USED AVAIL con-fs2-meta1 metadata 2177G 7085G con-fs2-meta2 data 0 7085G con-fs2-data data 1242T 4233T con-fs2-data-ec-ssd data 706G 22.1T con-fs2-data2 data 3409T 3848T STANDBY MDS ceph-10 ceph-08 ceph-09 ceph-12 MDS version: ceph version 15.2.17 (8a82819d84cf884bd39c17e3236e0632ac146dc4) octopus (stable)
There is no health issue:
# ceph status cluster: id: abc health: HEALTH_WARN 3 pgs not deep-scrubbed in time
services: mon: 5 daemons, quorum ceph-01,ceph-02,ceph-03,ceph-25,ceph-26 (age 9w) mgr: ceph-25(active, since 7w), standbys: ceph-26, ceph-01, ceph-03, ceph-02 mds: con-fs2:8 4 up:standby 8 up:active osd: 1284 osds: 1279 up (since 2d), 1279 in (since 5d)
task status:
data: pools: 14 pools, 25065 pgs objects: 2.20G objects, 3.9 PiB usage: 4.9 PiB used, 8.2 PiB / 13 PiB avail pgs: 25039 active+clean 26 active+clean+scrubbing+deep
io: client: 799 MiB/s rd, 55 MiB/s wr, 3.12k op/s rd, 1.82k op/s wr
The inconsistency seems undiagnosed, I couldn't find anything interesting in the cluster log. What should I look for and where?
I moved the folder to another location for diagnosis. Unfortunately, I don't have 2 clients any more showing different numbers, I see a 0 length now everywhere for the moved folder. I'm pretty sure though that the file still is non-zero length.
Thanks for any pointers. ================= Frank Schilder AIT Risø Campus Bygning 109, rum S14 _______________________________________________ ceph-users mailing list -- ceph-users@ceph.io<mailto:ceph-users@ceph.io> To unsubscribe send an email to ceph-users-leave@ceph.io<mailto:ceph-users-leave@ceph.io>
_______________________________________________ ceph-users mailing list -- ceph-users@ceph.io To unsubscribe send an email to ceph-users-leave@ceph.io
Hi Xiubo, I will try to answer questions from all your 3 e-mails here together with some new information we have. New: The problem occurs in newer python versions when using the shutil.copy function. There is also a function shutil.copy2 for which the problem does not show up. Copy2 behaves a bit like "cp -p" while copy is like "cp". The only code difference (linux) between these 2 functions is that copy calls copyfile+copymode while copy2 calls copyfile+copystat. For now we asked our users to use copy2 to avoid the issue. The copyfile function calls _fastcopy_sendfile on linux, which in turn calls os.sendfile, which seems to be part of libc: #include <sys/sendfile.h> ssize_t sendfile(int out_fd, int in_fd, off_t *offset, size_t count); I'm wondering if using this function requires explicit meta-data updates or should be safe on ceph-fs. I'm also not sure if a user-space client even supports this function (seems to be meaningless). Should this function be safe to use on ceph kclient? Answers to questions:
BTW, have you test the ceph-fuse with the same test ? Is also the same ? I don't have fuse clients available, so can't test right now.
Have you tried other ceph version ? We are in the process of deploying a new test cluster, the old one is scrapped already. I can't test this at the moment.
It looks like the cap update request was dropped to the ground in MDS. [...] If you can reproduce it, then please provide the mds logs by setting: [...] I can do a test with MDS logs on high level. Before I do that, looking at the python findings above, is this something that should work on ceph or is it a python issue?
Thanks for your help! ================= Frank Schilder AIT Risø Campus Bygning 109, rum S14
On 11/10/23 00:18, Frank Schilder wrote:
Hi Xiubo,
I will try to answer questions from all your 3 e-mails here together with some new information we have.
New: The problem occurs in newer python versions when using the shutil.copy function. There is also a function shutil.copy2 for which the problem does not show up. Copy2 behaves a bit like "cp -p" while copy is like "cp". The only code difference (linux) between these 2 functions is that copy calls copyfile+copymode while copy2 calls copyfile+copystat. For now we asked our users to use copy2 to avoid the issue.
The copyfile function calls _fastcopy_sendfile on linux, which in turn calls os.sendfile, which seems to be part of libc:
#include <sys/sendfile.h> ssize_t sendfile(int out_fd, int in_fd, off_t *offset, size_t count);
I'm wondering if using this function requires explicit meta-data updates or should be safe on ceph-fs. I'm also not sure if a user-space client even supports this function (seems to be meaningless). Should this function be safe to use on ceph kclient?
I didn't foresee any limit for this in kclient. The shutil.copy will only copy the contents of the file, while the shutil.copy2 will also copy the metadata. I need to know what exactly they do in kclient for shutil.copy and shutil.copy2.
Answers to questions:
BTW, have you test the ceph-fuse with the same test ? Is also the same ? I don't have fuse clients available, so can't test right now.
Have you tried other ceph version ? We are in the process of deploying a new test cluster, the old one is scrapped already. I can't test this at the moment.
It looks like the cap update request was dropped to the ground in MDS. [...] If you can reproduce it, then please provide the mds logs by setting: [...] I can do a test with MDS logs on high level. Before I do that, looking at the python findings above, is this something that should work on ceph or is it a python issue?
Not sure yet. I need to understand what exactly shutil.copy does in kclient. Thanks - Xiubo
Thanks for your help! ================= Frank Schilder AIT Risø Campus Bygning 109, rum S14
It looks like the cap update request was dropped to the ground in MDS. [...] If you can reproduce it, then please provide the mds logs by setting: [...] I can do a test with MDS logs on high level. Before I do that, looking at the python findings above, is this something that should work on ceph or is it a python issue?
Not sure yet. I need to understand what exactly shutil.copy does in kclient.
Thanks! Will wait for further instructions. ================= Frank Schilder AIT Risø Campus Bygning 109, rum S14 ________________________________________ From: Xiubo Li <xiubli@redhat.com> Sent: Friday, November 10, 2023 3:14 AM To: Frank Schilder; Gregory Farnum Cc: ceph-users@ceph.io Subject: Re: [ceph-users] Re: ceph fs (meta) data inconsistent On 11/10/23 00:18, Frank Schilder wrote:
Hi Xiubo,
I will try to answer questions from all your 3 e-mails here together with some new information we have.
New: The problem occurs in newer python versions when using the shutil.copy function. There is also a function shutil.copy2 for which the problem does not show up. Copy2 behaves a bit like "cp -p" while copy is like "cp". The only code difference (linux) between these 2 functions is that copy calls copyfile+copymode while copy2 calls copyfile+copystat. For now we asked our users to use copy2 to avoid the issue.
The copyfile function calls _fastcopy_sendfile on linux, which in turn calls os.sendfile, which seems to be part of libc:
#include <sys/sendfile.h> ssize_t sendfile(int out_fd, int in_fd, off_t *offset, size_t count);
I'm wondering if using this function requires explicit meta-data updates or should be safe on ceph-fs. I'm also not sure if a user-space client even supports this function (seems to be meaningless). Should this function be safe to use on ceph kclient?
I didn't foresee any limit for this in kclient. The shutil.copy will only copy the contents of the file, while the shutil.copy2 will also copy the metadata. I need to know what exactly they do in kclient for shutil.copy and shutil.copy2.
Answers to questions:
BTW, have you test the ceph-fuse with the same test ? Is also the same ? I don't have fuse clients available, so can't test right now.
Have you tried other ceph version ? We are in the process of deploying a new test cluster, the old one is scrapped already. I can't test this at the moment.
It looks like the cap update request was dropped to the ground in MDS. [...] If you can reproduce it, then please provide the mds logs by setting: [...] I can do a test with MDS logs on high level. Before I do that, looking at the python findings above, is this something that should work on ceph or is it a python issue?
Not sure yet. I need to understand what exactly shutil.copy does in kclient. Thanks - Xiubo
Thanks for your help! ================= Frank Schilder AIT Risø Campus Bygning 109, rum S14
Hi Frank, Locally I had some test by using the copy2 and copy, but they all worked well for me. Could you write a reproducing script ? Thanks - Xiubo On 11/10/23 22:53, Frank Schilder wrote:
It looks like the cap update request was dropped to the ground in MDS. [...] If you can reproduce it, then please provide the mds logs by setting: [...] I can do a test with MDS logs on high level. Before I do that, looking at the python findings above, is this something that should work on ceph or is it a python issue? Not sure yet. I need to understand what exactly shutil.copy does in kclient. Thanks! Will wait for further instructions. ================= Frank Schilder AIT Risø Campus Bygning 109, rum S14
________________________________________ From: Xiubo Li <xiubli@redhat.com> Sent: Friday, November 10, 2023 3:14 AM To: Frank Schilder; Gregory Farnum Cc: ceph-users@ceph.io Subject: Re: [ceph-users] Re: ceph fs (meta) data inconsistent
On 11/10/23 00:18, Frank Schilder wrote:
Hi Xiubo,
I will try to answer questions from all your 3 e-mails here together with some new information we have.
New: The problem occurs in newer python versions when using the shutil.copy function. There is also a function shutil.copy2 for which the problem does not show up. Copy2 behaves a bit like "cp -p" while copy is like "cp". The only code difference (linux) between these 2 functions is that copy calls copyfile+copymode while copy2 calls copyfile+copystat. For now we asked our users to use copy2 to avoid the issue.
The copyfile function calls _fastcopy_sendfile on linux, which in turn calls os.sendfile, which seems to be part of libc:
#include <sys/sendfile.h> ssize_t sendfile(int out_fd, int in_fd, off_t *offset, size_t count);
I'm wondering if using this function requires explicit meta-data updates or should be safe on ceph-fs. I'm also not sure if a user-space client even supports this function (seems to be meaningless). Should this function be safe to use on ceph kclient? I didn't foresee any limit for this in kclient.
The shutil.copy will only copy the contents of the file, while the shutil.copy2 will also copy the metadata. I need to know what exactly they do in kclient for shutil.copy and shutil.copy2.
Answers to questions:
BTW, have you test the ceph-fuse with the same test ? Is also the same ? I don't have fuse clients available, so can't test right now.
Have you tried other ceph version ? We are in the process of deploying a new test cluster, the old one is scrapped already. I can't test this at the moment.
It looks like the cap update request was dropped to the ground in MDS. [...] If you can reproduce it, then please provide the mds logs by setting: [...] I can do a test with MDS logs on high level. Before I do that, looking at the python findings above, is this something that should work on ceph or is it a python issue? Not sure yet. I need to understand what exactly shutil.copy does in kclient.
Thanks
- Xiubo
Thanks for your help! ================= Frank Schilder AIT Risø Campus Bygning 109, rum S14
I just raised one tracker to follow this: https://tracker.ceph.com/issues/63510 Thanks - Xiubo On 11/10/23 22:53, Frank Schilder wrote:
It looks like the cap update request was dropped to the ground in MDS. [...] If you can reproduce it, then please provide the mds logs by setting: [...] I can do a test with MDS logs on high level. Before I do that, looking at the python findings above, is this something that should work on ceph or is it a python issue? Not sure yet. I need to understand what exactly shutil.copy does in kclient. Thanks! Will wait for further instructions. ================= Frank Schilder AIT Risø Campus Bygning 109, rum S14
________________________________________ From: Xiubo Li <xiubli@redhat.com> Sent: Friday, November 10, 2023 3:14 AM To: Frank Schilder; Gregory Farnum Cc: ceph-users@ceph.io Subject: Re: [ceph-users] Re: ceph fs (meta) data inconsistent
On 11/10/23 00:18, Frank Schilder wrote:
Hi Xiubo,
I will try to answer questions from all your 3 e-mails here together with some new information we have.
New: The problem occurs in newer python versions when using the shutil.copy function. There is also a function shutil.copy2 for which the problem does not show up. Copy2 behaves a bit like "cp -p" while copy is like "cp". The only code difference (linux) between these 2 functions is that copy calls copyfile+copymode while copy2 calls copyfile+copystat. For now we asked our users to use copy2 to avoid the issue.
The copyfile function calls _fastcopy_sendfile on linux, which in turn calls os.sendfile, which seems to be part of libc:
#include <sys/sendfile.h> ssize_t sendfile(int out_fd, int in_fd, off_t *offset, size_t count);
I'm wondering if using this function requires explicit meta-data updates or should be safe on ceph-fs. I'm also not sure if a user-space client even supports this function (seems to be meaningless). Should this function be safe to use on ceph kclient? I didn't foresee any limit for this in kclient.
The shutil.copy will only copy the contents of the file, while the shutil.copy2 will also copy the metadata. I need to know what exactly they do in kclient for shutil.copy and shutil.copy2.
Answers to questions:
BTW, have you test the ceph-fuse with the same test ? Is also the same ? I don't have fuse clients available, so can't test right now.
Have you tried other ceph version ? We are in the process of deploying a new test cluster, the old one is scrapped already. I can't test this at the moment.
It looks like the cap update request was dropped to the ground in MDS. [...] If you can reproduce it, then please provide the mds logs by setting: [...] I can do a test with MDS logs on high level. Before I do that, looking at the python findings above, is this something that should work on ceph or is it a python issue? Not sure yet. I need to understand what exactly shutil.copy does in kclient.
Thanks
- Xiubo
Thanks for your help! ================= Frank Schilder AIT Risø Campus Bygning 109, rum S14
Hi Xiubo, thanks for the update. I will test your scripts in our system next week. Something important: running both scripts on a single client will not produce a difference. You need 2 clients. The inconsistency is between clients, not on the same client. For example: Setup: host1 and host2 with a kclient mount to a cephfs under /mnt/kcephfs Test 1 - on host1: execute shutil.copy2 - execute ls -l /mnt/kcephfs/ on host1 and host2: same result Test 2 - on host1: shutil.copy - execute ls -l /mnt/kcephfs/ on host1 and host2: file size=0 on host 2 while correct on host 1 Your scripts only show output of one host, but the inconsistency requires two hosts for observation. The stat information is updated on host1, but not synchronized to host2 in the second test. In case you can't reproduce that, I will append results from our system to the case. Also it would be important to know the python and libc versions. We observe this only for newer versions of both. Best regards, ================= Frank Schilder AIT Risø Campus Bygning 109, rum S14 ________________________________________ From: Xiubo Li <xiubli@redhat.com> Sent: Thursday, November 23, 2023 3:47 AM To: Frank Schilder; Gregory Farnum Cc: ceph-users@ceph.io Subject: Re: [ceph-users] Re: ceph fs (meta) data inconsistent I just raised one tracker to follow this: https://tracker.ceph.com/issues/63510 Thanks - Xiubo
On 11/24/23 21:37, Frank Schilder wrote:
Hi Xiubo,
thanks for the update. I will test your scripts in our system next week. Something important: running both scripts on a single client will not produce a difference. You need 2 clients. The inconsistency is between clients, not on the same client. For example:
Frank, Yeah, I did this with 2 different kclients. Thanks
Setup: host1 and host2 with a kclient mount to a cephfs under /mnt/kcephfs
Test 1 - on host1: execute shutil.copy2 - execute ls -l /mnt/kcephfs/ on host1 and host2: same result
Test 2 - on host1: shutil.copy - execute ls -l /mnt/kcephfs/ on host1 and host2: file size=0 on host 2 while correct on host 1
Your scripts only show output of one host, but the inconsistency requires two hosts for observation. The stat information is updated on host1, but not synchronized to host2 in the second test. In case you can't reproduce that, I will append results from our system to the case.
Also it would be important to know the python and libc versions. We observe this only for newer versions of both.
Best regards, ================= Frank Schilder AIT Risø Campus Bygning 109, rum S14
________________________________________ From: Xiubo Li <xiubli@redhat.com> Sent: Thursday, November 23, 2023 3:47 AM To: Frank Schilder; Gregory Farnum Cc: ceph-users@ceph.io Subject: Re: [ceph-users] Re: ceph fs (meta) data inconsistent
I just raised one tracker to follow this: https://tracker.ceph.com/issues/63510
Thanks
- Xiubo
Hi Xiubo, I uploaded a test script with session output showing the issue. When I look at your scripts, I can't see the stat-check on the second host anywhere. Hence, I don't really know what you are trying to compare. If you want me to run your test scripts on our system for comparison, please include the part executed on the second host explicitly in an ssh-command. Running your scripts alone in their current form will not reproduce the issue. Best regards, ================= Frank Schilder AIT Risø Campus Bygning 109, rum S14 ________________________________________ From: Xiubo Li <xiubli@redhat.com> Sent: Monday, November 27, 2023 3:59 AM To: Frank Schilder; Gregory Farnum Cc: ceph-users@ceph.io Subject: Re: [ceph-users] Re: ceph fs (meta) data inconsistent On 11/24/23 21:37, Frank Schilder wrote:
Hi Xiubo,
thanks for the update. I will test your scripts in our system next week. Something important: running both scripts on a single client will not produce a difference. You need 2 clients. The inconsistency is between clients, not on the same client. For example:
Frank, Yeah, I did this with 2 different kclients. Thanks
Setup: host1 and host2 with a kclient mount to a cephfs under /mnt/kcephfs
Test 1 - on host1: execute shutil.copy2 - execute ls -l /mnt/kcephfs/ on host1 and host2: same result
Test 2 - on host1: shutil.copy - execute ls -l /mnt/kcephfs/ on host1 and host2: file size=0 on host 2 while correct on host 1
Your scripts only show output of one host, but the inconsistency requires two hosts for observation. The stat information is updated on host1, but not synchronized to host2 in the second test. In case you can't reproduce that, I will append results from our system to the case.
Also it would be important to know the python and libc versions. We observe this only for newer versions of both.
Best regards, ================= Frank Schilder AIT Risø Campus Bygning 109, rum S14
________________________________________ From: Xiubo Li <xiubli@redhat.com> Sent: Thursday, November 23, 2023 3:47 AM To: Frank Schilder; Gregory Farnum Cc: ceph-users@ceph.io Subject: Re: [ceph-users] Re: ceph fs (meta) data inconsistent
I just raised one tracker to follow this: https://tracker.ceph.com/issues/63510
Thanks
- Xiubo
On 12/1/23 21:08, Frank Schilder wrote:
Hi Xiubo,
I uploaded a test script with session output showing the issue. When I look at your scripts, I can't see the stat-check on the second host anywhere. Hence, I don't really know what you are trying to compare.
Frank, I did that manually and that's not included in the script.
If you want me to run your test scripts on our system for comparison, please include the part executed on the second host explicitly in an ssh-command. Running your scripts alone in their current form will not reproduce the issue.
I saw your updating in the tracker and I will try it. Thanks - Xiubo
Best regards, ================= Frank Schilder AIT Risø Campus Bygning 109, rum S14
________________________________________ From: Xiubo Li <xiubli@redhat.com> Sent: Monday, November 27, 2023 3:59 AM To: Frank Schilder; Gregory Farnum Cc: ceph-users@ceph.io Subject: Re: [ceph-users] Re: ceph fs (meta) data inconsistent
On 11/24/23 21:37, Frank Schilder wrote:
Hi Xiubo,
thanks for the update. I will test your scripts in our system next week. Something important: running both scripts on a single client will not produce a difference. You need 2 clients. The inconsistency is between clients, not on the same client. For example: Frank,
Yeah, I did this with 2 different kclients.
Thanks
Setup: host1 and host2 with a kclient mount to a cephfs under /mnt/kcephfs
Test 1 - on host1: execute shutil.copy2 - execute ls -l /mnt/kcephfs/ on host1 and host2: same result
Test 2 - on host1: shutil.copy - execute ls -l /mnt/kcephfs/ on host1 and host2: file size=0 on host 2 while correct on host 1
Your scripts only show output of one host, but the inconsistency requires two hosts for observation. The stat information is updated on host1, but not synchronized to host2 in the second test. In case you can't reproduce that, I will append results from our system to the case.
Also it would be important to know the python and libc versions. We observe this only for newer versions of both.
Best regards, ================= Frank Schilder AIT Risø Campus Bygning 109, rum S14
________________________________________ From: Xiubo Li <xiubli@redhat.com> Sent: Thursday, November 23, 2023 3:47 AM To: Frank Schilder; Gregory Farnum Cc: ceph-users@ceph.io Subject: Re: [ceph-users] Re: ceph fs (meta) data inconsistent
I just raised one tracker to follow this: https://tracker.ceph.com/issues/63510
Thanks
- Xiubo
Frank, By using your script I still couldn't reproduce it. Locally my python version is 3.9.16, and I didn't have other VMs to test python other versions. Could you check the tracker to provide the debug logs ? Thanks - Xiubo On 12/1/23 21:08, Frank Schilder wrote:
Hi Xiubo,
I uploaded a test script with session output showing the issue. When I look at your scripts, I can't see the stat-check on the second host anywhere. Hence, I don't really know what you are trying to compare.
If you want me to run your test scripts on our system for comparison, please include the part executed on the second host explicitly in an ssh-command. Running your scripts alone in their current form will not reproduce the issue.
Best regards, ================= Frank Schilder AIT Risø Campus Bygning 109, rum S14
________________________________________ From: Xiubo Li <xiubli@redhat.com> Sent: Monday, November 27, 2023 3:59 AM To: Frank Schilder; Gregory Farnum Cc: ceph-users@ceph.io Subject: Re: [ceph-users] Re: ceph fs (meta) data inconsistent
On 11/24/23 21:37, Frank Schilder wrote:
Hi Xiubo,
thanks for the update. I will test your scripts in our system next week. Something important: running both scripts on a single client will not produce a difference. You need 2 clients. The inconsistency is between clients, not on the same client. For example: Frank,
Yeah, I did this with 2 different kclients.
Thanks
Setup: host1 and host2 with a kclient mount to a cephfs under /mnt/kcephfs
Test 1 - on host1: execute shutil.copy2 - execute ls -l /mnt/kcephfs/ on host1 and host2: same result
Test 2 - on host1: shutil.copy - execute ls -l /mnt/kcephfs/ on host1 and host2: file size=0 on host 2 while correct on host 1
Your scripts only show output of one host, but the inconsistency requires two hosts for observation. The stat information is updated on host1, but not synchronized to host2 in the second test. In case you can't reproduce that, I will append results from our system to the case.
Also it would be important to know the python and libc versions. We observe this only for newer versions of both.
Best regards, ================= Frank Schilder AIT Risø Campus Bygning 109, rum S14
________________________________________ From: Xiubo Li <xiubli@redhat.com> Sent: Thursday, November 23, 2023 3:47 AM To: Frank Schilder; Gregory Farnum Cc: ceph-users@ceph.io Subject: Re: [ceph-users] Re: ceph fs (meta) data inconsistent
I just raised one tracker to follow this: https://tracker.ceph.com/issues/63510
Thanks
- Xiubo
Hi Xiubo, I will update the case. I'm afraid this will have to wait a little bit though. I'm too occupied for a while and also don't have a test cluster that would help speed things up. I will update you, please keep the tracker open. Best regards, ================= Frank Schilder AIT Risø Campus Bygning 109, rum S14 ________________________________________ From: Xiubo Li <xiubli@redhat.com> Sent: Tuesday, December 5, 2023 1:58 AM To: Frank Schilder; Gregory Farnum Cc: ceph-users@ceph.io Subject: Re: [ceph-users] Re: ceph fs (meta) data inconsistent Frank, By using your script I still couldn't reproduce it. Locally my python version is 3.9.16, and I didn't have other VMs to test python other versions. Could you check the tracker to provide the debug logs ? Thanks - Xiubo On 12/1/23 21:08, Frank Schilder wrote:
Hi Xiubo,
I uploaded a test script with session output showing the issue. When I look at your scripts, I can't see the stat-check on the second host anywhere. Hence, I don't really know what you are trying to compare.
If you want me to run your test scripts on our system for comparison, please include the part executed on the second host explicitly in an ssh-command. Running your scripts alone in their current form will not reproduce the issue.
Best regards, ================= Frank Schilder AIT Risø Campus Bygning 109, rum S14
________________________________________ From: Xiubo Li <xiubli@redhat.com> Sent: Monday, November 27, 2023 3:59 AM To: Frank Schilder; Gregory Farnum Cc: ceph-users@ceph.io Subject: Re: [ceph-users] Re: ceph fs (meta) data inconsistent
On 11/24/23 21:37, Frank Schilder wrote:
Hi Xiubo,
thanks for the update. I will test your scripts in our system next week. Something important: running both scripts on a single client will not produce a difference. You need 2 clients. The inconsistency is between clients, not on the same client. For example: Frank,
Yeah, I did this with 2 different kclients.
Thanks
Setup: host1 and host2 with a kclient mount to a cephfs under /mnt/kcephfs
Test 1 - on host1: execute shutil.copy2 - execute ls -l /mnt/kcephfs/ on host1 and host2: same result
Test 2 - on host1: shutil.copy - execute ls -l /mnt/kcephfs/ on host1 and host2: file size=0 on host 2 while correct on host 1
Your scripts only show output of one host, but the inconsistency requires two hosts for observation. The stat information is updated on host1, but not synchronized to host2 in the second test. In case you can't reproduce that, I will append results from our system to the case.
Also it would be important to know the python and libc versions. We observe this only for newer versions of both.
Best regards, ================= Frank Schilder AIT Risø Campus Bygning 109, rum S14
________________________________________ From: Xiubo Li <xiubli@redhat.com> Sent: Thursday, November 23, 2023 3:47 AM To: Frank Schilder; Gregory Farnum Cc: ceph-users@ceph.io Subject: Re: [ceph-users] Re: ceph fs (meta) data inconsistent
I just raised one tracker to follow this: https://tracker.ceph.com/issues/63510
Thanks
- Xiubo
Hi Frank, Sure, just take your time. Thanks - Xiubo On 12/8/23 19:54, Frank Schilder wrote:
Hi Xiubo,
I will update the case. I'm afraid this will have to wait a little bit though. I'm too occupied for a while and also don't have a test cluster that would help speed things up. I will update you, please keep the tracker open.
Best regards, ================= Frank Schilder AIT Risø Campus Bygning 109, rum S14
________________________________________ From: Xiubo Li <xiubli@redhat.com> Sent: Tuesday, December 5, 2023 1:58 AM To: Frank Schilder; Gregory Farnum Cc: ceph-users@ceph.io Subject: Re: [ceph-users] Re: ceph fs (meta) data inconsistent
Frank,
By using your script I still couldn't reproduce it. Locally my python version is 3.9.16, and I didn't have other VMs to test python other versions.
Could you check the tracker to provide the debug logs ?
Thanks
- Xiubo
On 12/1/23 21:08, Frank Schilder wrote:
Hi Xiubo,
I uploaded a test script with session output showing the issue. When I look at your scripts, I can't see the stat-check on the second host anywhere. Hence, I don't really know what you are trying to compare.
If you want me to run your test scripts on our system for comparison, please include the part executed on the second host explicitly in an ssh-command. Running your scripts alone in their current form will not reproduce the issue.
Best regards, ================= Frank Schilder AIT Risø Campus Bygning 109, rum S14
________________________________________ From: Xiubo Li <xiubli@redhat.com> Sent: Monday, November 27, 2023 3:59 AM To: Frank Schilder; Gregory Farnum Cc: ceph-users@ceph.io Subject: Re: [ceph-users] Re: ceph fs (meta) data inconsistent
On 11/24/23 21:37, Frank Schilder wrote:
Hi Xiubo,
thanks for the update. I will test your scripts in our system next week. Something important: running both scripts on a single client will not produce a difference. You need 2 clients. The inconsistency is between clients, not on the same client. For example: Frank,
Yeah, I did this with 2 different kclients.
Thanks
Setup: host1 and host2 with a kclient mount to a cephfs under /mnt/kcephfs
Test 1 - on host1: execute shutil.copy2 - execute ls -l /mnt/kcephfs/ on host1 and host2: same result
Test 2 - on host1: shutil.copy - execute ls -l /mnt/kcephfs/ on host1 and host2: file size=0 on host 2 while correct on host 1
Your scripts only show output of one host, but the inconsistency requires two hosts for observation. The stat information is updated on host1, but not synchronized to host2 in the second test. In case you can't reproduce that, I will append results from our system to the case.
Also it would be important to know the python and libc versions. We observe this only for newer versions of both.
Best regards, ================= Frank Schilder AIT Risø Campus Bygning 109, rum S14
________________________________________ From: Xiubo Li <xiubli@redhat.com> Sent: Thursday, November 23, 2023 3:47 AM To: Frank Schilder; Gregory Farnum Cc: ceph-users@ceph.io Subject: Re: [ceph-users] Re: ceph fs (meta) data inconsistent
I just raised one tracker to follow this: https://tracker.ceph.com/issues/63510
Thanks
- Xiubo
On 11/1/23 23:57, Gregory Farnum wrote:
We have seen issues like this a few times and they have all been kernel client bugs with CephFS’ internal “capability” file locking protocol. I’m not aware of any extant bugs like this in our code base, but kernel patches can take a long and winding path before they end up on deployed systems.
Most likely, if you were to restart some combination of the client which wrote the file and the client(s) reading it, the size would propagate correctly. As long as you’ve synced the data, it’s definitely present in the cluster.
Adding Xiubo, who has worked on these and may have other comments. -Greg
As I remembered we have some fixes about snapshot like this in kclient. And also one ctime inconsistency issue in MDS. But this sounds more like a MDS side bug. I just went through the kclient patches and didn't find any commit that is fixing this yet. Thanks - Xiubo
On Wed, Nov 1, 2023 at 7:16 AM Frank Schilder <frans@dtu.dk> wrote:
Dear fellow cephers,
today we observed a somewhat worrisome inconsistency on our ceph fs. A file created on one host showed up as 0 length on all other hosts:
[user1@host1 h2lib]$ ls -lh total 37M -rw-rw---- 1 user1 user1 12K Nov 1 11:59 dll_wrapper.py
[user2@host2 h2lib]# ls -l total 34 -rw-rw----. 1 user1 user1 0 Nov 1 11:59 dll_wrapper.py
[user1@host1 h2lib]$ cp dll_wrapper.py dll_wrapper.py.test [user1@host1 h2lib]$ ls -l total 37199 -rw-rw---- 1 user1 user1 11641 Nov 1 11:59 dll_wrapper.py -rw-rw---- 1 user1 user1 11641 Nov 1 13:10 dll_wrapper.py.test
[user2@host2 h2lib]# ls -l total 45 -rw-rw----. 1 user1 user1 0 Nov 1 11:59 dll_wrapper.py -rw-rw----. 1 user1 user1 11641 Nov 1 13:10 dll_wrapper.py.test
Executing a sync on all these hosts did not help. However, deleting the problematic file and replacing it with a copy seemed to work around the issue. We saw this with ceph kclients of different versions, it seems to be on the MDS side.
How can this happen and how dangerous is it?
ceph fs status (showing ceph version):
# ceph fs status con-fs2 - 1662 clients ======= RANK STATE MDS ACTIVITY DNS INOS 0 active ceph-15 Reqs: 14 /s 2307k 2278k 1 active ceph-11 Reqs: 159 /s 4208k 4203k 2 active ceph-17 Reqs: 3 /s 4533k 4501k 3 active ceph-24 Reqs: 3 /s 4593k 4300k 4 active ceph-14 Reqs: 1 /s 4228k 4226k 5 active ceph-13 Reqs: 5 /s 1994k 1782k 6 active ceph-16 Reqs: 8 /s 5022k 4841k 7 active ceph-23 Reqs: 9 /s 4140k 4116k POOL TYPE USED AVAIL con-fs2-meta1 metadata 2177G 7085G con-fs2-meta2 data 0 7085G con-fs2-data data 1242T 4233T con-fs2-data-ec-ssd data 706G 22.1T con-fs2-data2 data 3409T 3848T STANDBY MDS ceph-10 ceph-08 ceph-09 ceph-12 MDS version: ceph version 15.2.17 (8a82819d84cf884bd39c17e3236e0632ac146dc4) octopus (stable)
There is no health issue:
# ceph status cluster: id: abc health: HEALTH_WARN 3 pgs not deep-scrubbed in time
services: mon: 5 daemons, quorum ceph-01,ceph-02,ceph-03,ceph-25,ceph-26 (age 9w) mgr: ceph-25(active, since 7w), standbys: ceph-26, ceph-01, ceph-03, ceph-02 mds: con-fs2:8 4 up:standby 8 up:active osd: 1284 osds: 1279 up (since 2d), 1279 in (since 5d)
task status:
data: pools: 14 pools, 25065 pgs objects: 2.20G objects, 3.9 PiB usage: 4.9 PiB used, 8.2 PiB / 13 PiB avail pgs: 25039 active+clean 26 active+clean+scrubbing+deep
io: client: 799 MiB/s rd, 55 MiB/s wr, 3.12k op/s rd, 1.82k op/s wr
The inconsistency seems undiagnosed, I couldn't find anything interesting in the cluster log. What should I look for and where?
I moved the folder to another location for diagnosis. Unfortunately, I don't have 2 clients any more showing different numbers, I see a 0 length now everywhere for the moved folder. I'm pretty sure though that the file still is non-zero length.
Thanks for any pointers. ================= Frank Schilder AIT Risø Campus Bygning 109, rum S14 _______________________________________________ ceph-users mailing list -- ceph-users@ceph.io To unsubscribe send an email to ceph-users-leave@ceph.io
On 11/1/23 22:14, Frank Schilder wrote:
Dear fellow cephers,
today we observed a somewhat worrisome inconsistency on our ceph fs. A file created on one host showed up as 0 length on all other hosts:
[user1@host1 h2lib]$ ls -lh total 37M -rw-rw---- 1 user1 user1 12K Nov 1 11:59 dll_wrapper.py
[user2@host2 h2lib]# ls -l total 34 -rw-rw----. 1 user1 user1 0 Nov 1 11:59 dll_wrapper.py
[user1@host1 h2lib]$ cp dll_wrapper.py dll_wrapper.py.test [user1@host1 h2lib]$ ls -l total 37199 -rw-rw---- 1 user1 user1 11641 Nov 1 11:59 dll_wrapper.py -rw-rw---- 1 user1 user1 11641 Nov 1 13:10 dll_wrapper.py.test
[user2@host2 h2lib]# ls -l total 45 -rw-rw----. 1 user1 user1 0 Nov 1 11:59 dll_wrapper.py -rw-rw----. 1 user1 user1 11641 Nov 1 13:10 dll_wrapper.py.test
Executing a sync on all these hosts did not help. However, deleting the problematic file and replacing it with a copy seemed to work around the issue. We saw this with ceph kclients of different versions, it seems to be on the MDS side.
Sorry for late Frank. BTW, have you test the ceph-fuse with the same test ? Is also the same ?
How can this happen and how dangerous is it?
ceph fs status (showing ceph version):
# ceph fs status con-fs2 - 1662 clients ======= RANK STATE MDS ACTIVITY DNS INOS 0 active ceph-15 Reqs: 14 /s 2307k 2278k 1 active ceph-11 Reqs: 159 /s 4208k 4203k 2 active ceph-17 Reqs: 3 /s 4533k 4501k 3 active ceph-24 Reqs: 3 /s 4593k 4300k 4 active ceph-14 Reqs: 1 /s 4228k 4226k 5 active ceph-13 Reqs: 5 /s 1994k 1782k 6 active ceph-16 Reqs: 8 /s 5022k 4841k 7 active ceph-23 Reqs: 9 /s 4140k 4116k POOL TYPE USED AVAIL con-fs2-meta1 metadata 2177G 7085G con-fs2-meta2 data 0 7085G con-fs2-data data 1242T 4233T con-fs2-data-ec-ssd data 706G 22.1T con-fs2-data2 data 3409T 3848T STANDBY MDS ceph-10 ceph-08 ceph-09 ceph-12 MDS version: ceph version 15.2.17 (8a82819d84cf884bd39c17e3236e0632ac146dc4) octopus (stable)
Have you tried other ceph version ? Thanks - Xiubo
There is no health issue:
# ceph status cluster: id: abc health: HEALTH_WARN 3 pgs not deep-scrubbed in time
services: mon: 5 daemons, quorum ceph-01,ceph-02,ceph-03,ceph-25,ceph-26 (age 9w) mgr: ceph-25(active, since 7w), standbys: ceph-26, ceph-01, ceph-03, ceph-02 mds: con-fs2:8 4 up:standby 8 up:active osd: 1284 osds: 1279 up (since 2d), 1279 in (since 5d)
task status:
data: pools: 14 pools, 25065 pgs objects: 2.20G objects, 3.9 PiB usage: 4.9 PiB used, 8.2 PiB / 13 PiB avail pgs: 25039 active+clean 26 active+clean+scrubbing+deep
io: client: 799 MiB/s rd, 55 MiB/s wr, 3.12k op/s rd, 1.82k op/s wr
The inconsistency seems undiagnosed, I couldn't find anything interesting in the cluster log. What should I look for and where?
I moved the folder to another location for diagnosis. Unfortunately, I don't have 2 clients any more showing different numbers, I see a 0 length now everywhere for the moved folder. I'm pretty sure though that the file still is non-zero length.
Thanks for any pointers. ================= Frank Schilder AIT Risø Campus Bygning 109, rum S14 _______________________________________________ ceph-users mailing list -- ceph-users@ceph.io To unsubscribe send an email to ceph-users-leave@ceph.io
participants (3)
-
Frank Schilder
-
Gregory Farnum
-
Xiubo Li