Bug #56450
Rados doesn't release the disk spaces after cephfs releases it
0%
Description
Before running the Filesystem benchmark test, from OS we can see that the /_ directory had _81GB:
[root@lxbceph1 kcephfs]# df -h Filesystem Size Used Avail Use% Mounted on devtmpfs 14G 4.0K 14G 1% /dev tmpfs 14G 84K 14G 1% /dev/shm tmpfs 14G 50M 14G 1% /run tmpfs 14G 0 14G 0% /sys/fs/cgroup /dev/mapper/rhel-root 235G 155G 81G 66% / /dev/sda1 15G 1.4G 14G 9% /boot /dev/loop1 39M 39M 0 100% /var/lib/snapd/snap/gh/545 /dev/loop0 39M 39M 0 100% /var/lib/snapd/snap/gh/544 /dev/loop4 56M 56M 0 100% /var/lib/snapd/snap/core18/2409 /dev/loop2 45M 45M 0 100% /var/lib/snapd/snap/snapd/15904 /dev/loop3 56M 56M 0 100% /var/lib/snapd/snap/core18/1944 tmpfs 2.8G 16K 2.8G 1% /run/user/42 tmpfs 2.8G 0 2.8G 0% /run/user/0 10.72.47.117:40545,10.72.47.117:40547,10.72.47.117:40549:/ 99G 0 99G 0% /mnt/kcephfs
And after the test finished, it had 26GB:
[root@lxbceph1 usr]# df -h Filesystem Size Used Avail Use% Mounted on devtmpfs 14G 4.0K 14G 1% /dev tmpfs 14G 84K 14G 1% /dev/shm tmpfs 14G 50M 14G 1% /run tmpfs 14G 0 14G 0% /sys/fs/cgroup /dev/mapper/rhel-root 235G 210G 26G 90% / /dev/sda1 15G 1.4G 14G 9% /boot /dev/loop1 39M 39M 0 100% /var/lib/snapd/snap/gh/545 /dev/loop0 39M 39M 0 100% /var/lib/snapd/snap/gh/544 /dev/loop4 56M 56M 0 100% /var/lib/snapd/snap/core18/2409 /dev/loop2 45M 45M 0 100% /var/lib/snapd/snap/snapd/15904 /dev/loop3 56M 56M 0 100% /var/lib/snapd/snap/core18/1944 tmpfs 2.8G 16K 2.8G 1% /run/user/42 tmpfs 2.8G 0 2.8G 0% /run/user/0 10.72.47.117:40545,10.72.47.117:40547,10.72.47.117:40549:/ 99G 0 99G 0% /mnt/kcephfs
And from ceph df we can see that the spaces had been released:
[root@lxbceph1 build]# ./bin/ceph df --- RAW STORAGE --- CLASS SIZE AVAIL USED RAW USED %RAW USED hdd 303 GiB 300 GiB 3.5 GiB 3.5 GiB 1.14 TOTAL 303 GiB 300 GiB 3.5 GiB 3.5 GiB 1.14 --- POOLS --- POOL ID PGS STORED OBJECTS USED %USED MAX AVAIL .mgr 1 1 577 KiB 2 1.7 MiB 0 99 GiB cephfs.a.meta 2 16 156 MiB 61 468 MiB 0.15 99 GiB cephfs.a.data 3 32 0 B 0 0 B 0 99 GiB
If I run the same test again it will fail with no disk spaces and from the df -h we can see that the disk spaces from OS has been used up:
[root@lxbceph1 usr]# df -h Filesystem Size Used Avail Use% Mounted on devtmpfs 14G 4.0K 14G 1% /dev tmpfs 14G 84K 14G 1% /dev/shm tmpfs 14G 50M 14G 1% /run tmpfs 14G 0 14G 0% /sys/fs/cgroup /dev/mapper/rhel-root 235G 235G 103M 100% / /dev/sda1 15G 1.4G 14G 9% /boot /dev/loop1 39M 39M 0 100% /var/lib/snapd/snap/gh/545 /dev/loop0 39M 39M 0 100% /var/lib/snapd/snap/gh/544 /dev/loop4 56M 56M 0 100% /var/lib/snapd/snap/core18/2409 /dev/loop2 45M 45M 0 100% /var/lib/snapd/snap/snapd/15904 /dev/loop3 56M 56M 0 100% /var/lib/snapd/snap/core18/1944 tmpfs 2.8G 16K 2.8G 1% /run/user/42 tmpfs 2.8G 0 2.8G 0% /run/user/0 10.72.47.117:40545,10.72.47.117:40547,10.72.47.117:40549:/ 99G 8.5G 91G 9% /mnt/kcephfs
Is this a bug ? If not how to fix this ?
History
#1 Updated by Xiubo Li 7 months ago
There is only one active MDS:
[root@lxbceph1 build]# ./bin/ceph tell mds.0 perf dump { "AsyncMessenger::Worker-0": { "msgr_recv_messages": 5447, "msgr_send_messages": 5432, "msgr_recv_bytes": 1325936, "msgr_send_bytes": 44140261, "msgr_created_connections": 16, "msgr_active_connections": 4, "msgr_running_total_time": 3.703740747, "msgr_running_send_time": 2.608667402, "msgr_running_recv_time": 0.580923595, "msgr_running_fast_dispatch_time": 0.345006849, "msgr_send_messages_queue_lat": { "avgcount": 5432, "sum": 1.122213825, "avgtime": 0.000206593 }, "msgr_handle_ack_lat": { "avgcount": 3, "sum": 0.000000535, "avgtime": 0.000000178 } }, "AsyncMessenger::Worker-1": { "msgr_recv_messages": 63295, "msgr_send_messages": 58419, "msgr_recv_bytes": 20388247, "msgr_send_bytes": 24653703, "msgr_created_connections": 9, "msgr_active_connections": 3, "msgr_running_total_time": 25.785345095, "msgr_running_send_time": 17.249171571, "msgr_running_recv_time": 24.521180684, "msgr_running_fast_dispatch_time": 0.602114896, "msgr_send_messages_queue_lat": { "avgcount": 58419, "sum": 43.295204754, "avgtime": 0.000741115 }, "msgr_handle_ack_lat": { "avgcount": 3976, "sum": 0.060003029, "avgtime": 0.000015091 } }, "AsyncMessenger::Worker-2": { "msgr_recv_messages": 3628, "msgr_send_messages": 3435, "msgr_recv_bytes": 892515, "msgr_send_bytes": 109308654, "msgr_created_connections": 19, "msgr_active_connections": 3, "msgr_running_total_time": 2.595886977, "msgr_running_send_time": 1.774296087, "msgr_running_recv_time": 0.408155437, "msgr_running_fast_dispatch_time": 0.369999079, "msgr_send_messages_queue_lat": { "avgcount": 3435, "sum": 1.585131581, "avgtime": 0.000461464 }, "msgr_handle_ack_lat": { "avgcount": 231, "sum": 0.000309807, "avgtime": 0.000001341 } }, "cct": { "total_workers": 1, "unhealthy_workers": 0 }, "finisher-MDSRank": { "queue_len": 0, "complete_latency": { "avgcount": 3465, "sum": 0.979409072, "avgtime": 0.000282657 } }, "finisher-PurgeQueue": { "queue_len": 0, "complete_latency": { "avgcount": 2575, "sum": 0.133727329, "avgtime": 0.000051932 } }, "mds": { "request": 1775, "reply": 1775, "reply_latency": { "avgcount": 1775, "sum": 13.278235106, "avgtime": 0.007480695 }, "slow_reply": 0, "forward": 0, "dir_fetch_complete": 0, "dir_fetch_keys": 0, "dir_commit": 12, "dir_split": 0, "dir_merge": 0, "inodes": 15, "inodes_top": 0, "inodes_bottom": 15, "inodes_pin_tail": 0, "inodes_pinned": 15, "inodes_expired": 0, "inodes_with_caps": 1, "caps": 2, "subtrees": 2, "traverse": 1932, "traverse_hit": 1787, "traverse_forward": 0, "traverse_discover": 0, "traverse_dir_fetch": 0, "traverse_remote_ino": 0, "traverse_lock": 23, "load_cent": 0, "q": 0, "exported": 0, "exported_inodes": 0, "imported": 0, "imported_inodes": 0, "openino_dir_fetch": 0, "openino_backtrace_fetch": 0, "openino_peer_discover": 0, "root_rfiles": 0, "root_rbytes": 0, "root_rsnaps": 0, "scrub_backtrace_fetch": 0, "scrub_set_tag": 0, "scrub_backtrace_repaired": 0, "scrub_inotable_repaired": 0, "scrub_dir_inodes": 0, "scrub_dir_base_inodes": 0, "scrub_dirfrag_rstats": 0, "scrub_file_inodes": 0, "handle_inode_file_caps": 0, "ceph_cap_op_revoke": 279, "ceph_cap_op_grant": 3295, "ceph_cap_op_trunc": 6, "ceph_cap_op_flushsnap_ack": 0, "ceph_cap_op_flush_ack": 0, "handle_client_caps": 50083, "handle_client_caps_dirty": 49001, "handle_client_cap_release": 24, "process_request_cap_release": 963 }, "mds_cache": { "num_strays": 0, "num_strays_delayed": 0, "num_strays_enqueuing": 0, "strays_created": 758, "strays_enqueued": 756, "strays_reintegrated": 8, "strays_migrated": 0, "num_recovering_processing": 0, "num_recovering_enqueued": 0, "num_recovering_prioritized": 0, "recovery_started": 0, "recovery_completed": 0, "ireq_enqueue_scrub": 0, "ireq_exportdir": 0, "ireq_flush": 0, "ireq_fragmentdir": 0, "ireq_fragstats": 0, "ireq_inodestats": 0 }, "mds_log": { "evadd": 104834, "evex": 0, "evtrm": 0, "ev": 104834, "evexg": 0, "evexd": 0, "segadd": 110, "segex": 0, "segtrm": 0, "seg": 110, "segexg": 0, "segexd": 0, "expos": 4194304, "wrpos": 154265037, "rdpos": 0, "jlat": { "avgcount": 1909, "sum": 2573.992130569, "avgtime": 1.348345799 }, "replayed": 0 }, "mds_mem": { "ino": 13, "ino+": 769, "ino-": 756, "dir": 12, "dir+": 52, "dir-": 40, "dn": 15, "dn+": 1273, "dn-": 1258, "cap": 2, "cap+": 758, "cap-": 756, "rss": 131160, "heap": 53516 }, "mds_server": { "dispatch_client_request": 2075, "dispatch_server_request": 0, "handle_client_request": 1775, "handle_client_session": 640, "handle_peer_request": 0, "req_create_latency": { "avgcount": 703, "sum": 0.631953820, "avgtime": 0.000898938 }, "req_getattr_latency": { "avgcount": 6, "sum": 0.046813225, "avgtime": 0.007802204 }, "req_getfilelock_latency": { "avgcount": 0, "sum": 0.000000000, "avgtime": 0.000000000 }, "req_link_latency": { "avgcount": 2, "sum": 0.000922207, "avgtime": 0.000461103 }, "req_lookup_latency": { "avgcount": 9, "sum": 0.037134315, "avgtime": 0.004126035 }, "req_lookuphash_latency": { "avgcount": 0, "sum": 0.000000000, "avgtime": 0.000000000 }, "req_lookupino_latency": { "avgcount": 0, "sum": 0.000000000, "avgtime": 0.000000000 }, "req_lookupname_latency": { "avgcount": 0, "sum": 0.000000000, "avgtime": 0.000000000 }, "req_lookupparent_latency": { "avgcount": 0, "sum": 0.000000000, "avgtime": 0.000000000 }, "req_lookupsnap_latency": { "avgcount": 0, "sum": 0.000000000, "avgtime": 0.000000000 }, "req_lssnap_latency": { "avgcount": 0, "sum": 0.000000000, "avgtime": 0.000000000 }, "req_mkdir_latency": { "avgcount": 40, "sum": 0.016004791, "avgtime": 0.000400119 }, "req_mknod_latency": { "avgcount": 0, "sum": 0.000000000, "avgtime": 0.000000000 }, "req_mksnap_latency": { "avgcount": 0, "sum": 0.000000000, "avgtime": 0.000000000 }, "req_open_latency": { "avgcount": 95, "sum": 0.021608215, "avgtime": 0.000227454 }, "req_readdir_latency": { "avgcount": 112, "sum": 2.459501600, "avgtime": 0.021959835 }, "req_rename_latency": { "avgcount": 58, "sum": 0.485200034, "avgtime": 0.008365517 }, "req_renamesnap_latency": { "avgcount": 0, "sum": 0.000000000, "avgtime": 0.000000000 }, "req_rmdir_latency": { "avgcount": 40, "sum": 8.878596447, "avgtime": 0.221964911 }, "req_rmsnap_latency": { "avgcount": 0, "sum": 0.000000000, "avgtime": 0.000000000 }, "req_rmxattr_latency": { "avgcount": 0, "sum": 0.000000000, "avgtime": 0.000000000 }, "req_setattr_latency": { "avgcount": 6, "sum": 0.177777015, "avgtime": 0.029629502 }, "req_setdirlayout_latency": { "avgcount": 0, "sum": 0.000000000, "avgtime": 0.000000000 }, "req_setfilelock_latency": { "avgcount": 4, "sum": 0.001203897, "avgtime": 0.000300974 }, "req_setlayout_latency": { "avgcount": 0, "sum": 0.000000000, "avgtime": 0.000000000 }, "req_setxattr_latency": { "avgcount": 2, "sum": 0.005657284, "avgtime": 0.002828642 }, "req_symlink_latency": { "avgcount": 13, "sum": 0.004986039, "avgtime": 0.000383541 }, "req_unlink_latency": { "avgcount": 685, "sum": 0.510876217, "avgtime": 0.000745804 }, "cap_revoke_eviction": 0, "cap_acquisition_throttle": 0, "req_getvxattr_latency": { "avgcount": 0, "sum": 0.000000000, "avgtime": 0.000000000 } }, "mds_sessions": { "session_count": 2, "session_add": 2, "session_remove": 0, "sessions_open": 2, "sessions_stale": 0, "total_load": 1, "average_load": 0, "avg_session_uptime": 5380 }, "mempool": { "bloom_filter_bytes": 0, "bloom_filter_items": 0, "bluestore_alloc_bytes": 0, "bluestore_alloc_items": 0, "bluestore_cache_data_bytes": 0, "bluestore_cache_data_items": 0, "bluestore_cache_onode_bytes": 0, "bluestore_cache_onode_items": 0, "bluestore_cache_meta_bytes": 0, "bluestore_cache_meta_items": 0, "bluestore_cache_other_bytes": 0, "bluestore_cache_other_items": 0, "bluestore_Buffer_bytes": 0, "bluestore_Buffer_items": 0, "bluestore_Extent_bytes": 0, "bluestore_Extent_items": 0, "bluestore_Blob_bytes": 0, "bluestore_Blob_items": 0, "bluestore_SharedBlob_bytes": 0, "bluestore_SharedBlob_items": 0, "bluestore_inline_bl_bytes": 0, "bluestore_inline_bl_items": 0, "bluestore_fsck_bytes": 0, "bluestore_fsck_items": 0, "bluestore_txc_bytes": 0, "bluestore_txc_items": 0, "bluestore_writing_deferred_bytes": 0, "bluestore_writing_deferred_items": 0, "bluestore_writing_bytes": 0, "bluestore_writing_items": 0, "bluefs_bytes": 0, "bluefs_items": 0, "bluefs_file_reader_bytes": 0, "bluefs_file_reader_items": 0, "bluefs_file_writer_bytes": 0, "bluefs_file_writer_items": 0, "buffer_anon_bytes": 170706, "buffer_anon_items": 20, "buffer_meta_bytes": 0, "buffer_meta_items": 0, "osd_bytes": 0, "osd_items": 0, "osd_mapbl_bytes": 0, "osd_mapbl_items": 0, "osd_pglog_bytes": 0, "osd_pglog_items": 0, "osdmap_bytes": 4520, "osdmap_items": 37, "osdmap_mapping_bytes": 0, "osdmap_mapping_items": 0, "pgmap_bytes": 0, "pgmap_items": 0, "mds_co_bytes": 56624, "mds_co_items": 295, "unittest_1_bytes": 0, "unittest_1_items": 0, "unittest_2_bytes": 0, "unittest_2_items": 0 }, "objecter": { "op_active": 0, "op_laggy": 0, "op_send": 6156, "op_send_bytes": 150248147, "op_resend": 31, "op_reply": 6156, "op_latency": { "avgcount": 6156, "sum": 3560.940598179, "avgtime": 0.578450389 }, "op_inflight": 0, "oplen_avg": { "avgcount": 6156, "sum": 6392 }, "op": 6156, "op_r": 37, "op_w": 6119, "op_rmw": 0, "op_pg": 0, "osdop_stat": 0, "osdop_create": 11, "osdop_read": 37, "osdop_write": 1946, "osdop_writefull": 98, "osdop_writesame": 0, "osdop_append": 0, "osdop_zero": 0, "osdop_truncate": 0, "osdop_delete": 3875, "osdop_mapext": 0, "osdop_sparse_read": 0, "osdop_clonerange": 0, "osdop_getxattr": 0, "osdop_setxattr": 22, "osdop_cmpxattr": 0, "osdop_rmxattr": 0, "osdop_resetxattrs": 0, "osdop_call": 0, "osdop_watch": 0, "osdop_notify": 0, "osdop_src_cmpxattr": 0, "osdop_pgls": 0, "osdop_pgls_filter": 0, "osdop_other": 6, "linger_active": 0, "linger_send": 0, "linger_resend": 0, "linger_ping": 0, "poolop_active": 0, "poolop_send": 0, "poolop_resend": 0, "poolstat_active": 0, "poolstat_send": 0, "poolstat_resend": 0, "statfs_active": 0, "statfs_send": 0, "statfs_resend": 0, "command_active": 0, "command_send": 0, "command_resend": 0, "map_epoch": 55, "map_full": 0, "map_inc": 34, "osd_sessions": 3, "osd_session_open": 26, "osd_session_close": 23, "osd_laggy": 0, "omap_wr": 292, "omap_rd": 0, "omap_del": 105 }, "oft": { "omap_total_objs": 1, "omap_total_kv_pairs": 0, "omap_total_updates": 0, "omap_total_removes": 0 }, "purge_queue": { "pq_executing_ops": 0, "pq_executing_ops_high_water": 21, "pq_executing": 0, "pq_executing_high_water": 16, "pq_executed": 756, "pq_item_in_journal": 0 }, "throttle-msgr_dispatch_throttler-mds": { "val": 0, "max": 104857600, "get_started": 0, "get": 72370, "get_sum": 17251318, "get_or_fail_fail": 0, "get_or_fail_success": 72370, "take": 0, "take_sum": 0, "put": 72370, "put_sum": 17251318, "wait": { "avgcount": 0, "sum": 0.000000000, "avgtime": 0.000000000 } }, "throttle-objecter_bytes": { "val": 0, "max": 104857600, "get_started": 0, "get": 0, "get_sum": 0, "get_or_fail_fail": 0, "get_or_fail_success": 0, "take": 6156, "take_sum": 150324503, "put": 6156, "put_sum": 150324503, "wait": { "avgcount": 0, "sum": 0.000000000, "avgtime": 0.000000000 } }, "throttle-objecter_ops": { "val": 0, "max": 1024, "get_started": 0, "get": 0, "get_sum": 0, "get_or_fail_fail": 0, "get_or_fail_success": 0, "take": 6156, "take_sum": 6156, "put": 6156, "put_sum": 6156, "wait": { "avgcount": 0, "sum": 0.000000000, "avgtime": 0.000000000 } }, "throttle-write_buf_throttle": { "val": 0, "max": 3758096384, "get_started": 0, "get": 756, "get_sum": 76356, "get_or_fail_fail": 0, "get_or_fail_success": 756, "take": 0, "take_sum": 0, "put": 37, "put_sum": 76356, "wait": { "avgcount": 0, "sum": 0.000000000, "avgtime": 0.000000000 } }, "throttle-write_buf_throttle-0x5611e325fc70": { "val": 0, "max": 3758096384, "get_started": 0, "get": 104834, "get_sum": 150070733, "get_or_fail_fail": 0, "get_or_fail_success": 104834, "take": 0, "take_sum": 0, "put": 1909, "put_sum": 150070733, "wait": { "avgcount": 0, "sum": 0.000000000, "avgtime": 0.000000000 } } }
#2 Updated by Greg Farnum 7 months ago
So this looks like the client is not correctly updating its own df reporting, but that the data is actually getting cleaned up or else "ceph df" would not be reporting the data is all freed. Right?
Is this with ceph-fuse or the kernel client? Or both?
#4 Updated by Xiubo Li 7 months ago
Greg Farnum wrote:
So this looks like the client is not correctly updating its own df reporting, but that the data is actually getting cleaned up or else "ceph df" would not be reporting the data is all freed. Right?
I didn't see anywhere is reporting this in the client side, could you point out where is doing this ? Or where should it be ?
I see the output from the ceph df is as expected.
Is this with ceph-fuse or the kernel client? Or both?
Both have the same issue.
#5 Updated by Xiubo Li 7 months ago
Tried:
1, to umount the kclients or fuse clients
2, restart all the MDS daemons
3, restart all the OSD daemons
4, restart all the MON daemons
5, restart all the MGR daemons
And then run the df, still the same. Unless after the cluster is stopped and then the build/dev/ is deleted will the disk spaces be released.
#6 Updated by Greg Farnum 7 months ago
Xiubo Li wrote:
Greg Farnum wrote:
So this looks like the client is not correctly updating its own df reporting, but that the data is actually getting cleaned up or else "ceph df" would not be reporting the data is all freed. Right?
I didn't see anywhere is reporting this in the client side, could you point out where is doing this ? Or where should it be ?
I see the output from the ceph df is as expected.
Is this with ceph-fuse or the kernel client? Or both?
Both have the same issue.
Oh, I misunderstood this ticket. Never mind me.
I'd imagine this has something to do with how we're looping bluestore, rather than a bug in RADOS proper?
#7 Updated by Xiubo Li 7 months ago
- Project changed from RADOS to bluestore
Greg Farnum wrote:
Xiubo Li wrote:
Greg Farnum wrote:
So this looks like the client is not correctly updating its own df reporting, but that the data is actually getting cleaned up or else "ceph df" would not be reporting the data is all freed. Right?
I didn't see anywhere is reporting this in the client side, could you point out where is doing this ? Or where should it be ?
I see the output from the ceph df is as expected.
Is this with ceph-fuse or the kernel client? Or both?
Both have the same issue.
Oh, I misunderstood this ticket. Never mind me.
I'd imagine this has something to do with how we're looping bluestore, rather than a bug in RADOS proper?
Yeah, discussed this with Milind yesterday and yeah it's more like a bug in bluestore. I thought the bluestore belongs to Rados component. I will change it.
Thanks Greg!