If it was just one instance I would just bounce it but the thing is this happens when we join/remove nodes, and we have a lot of servers with this issue (while before the join/remove we are on ~50% disk usage). We found ourselves fighting with compaction to make sure we don't run out of space. Will open a ticket, thanks.
On Wed, Apr 5, 2023 at 12:10 AM Jeff Jirsa <jji...@gmail.com> wrote: > If you restart the node, it'll process/purge those compaction logs on > startup, but you want them to purge/process now. > > I genuinely dont know when the tidier runs, but it's likely the case that > you're too busy compaction to purge (though I don't know what exactly "too > busy" means). > > Since you're close to 95% disk full, bounce one instance at a time to > recover the space, but we probably need a JIRA to understand exactly what's > blocking the tidier from running. > > > > On Tue, Apr 4, 2023 at 1:55 PM Gil Ganz <gilg...@gmail.com> wrote: > >> More information - from another node in the cluster >> >> I can see many txn files although I only have two compactions running. >> [user@server808 new_table-44263b406bf111ed8bd9df80ace3677a]# ls -l *txn* >> -rw-r--r-- 1 cassandra cassandra 613 Apr 4 05:26 >> nb_txn_compaction_09e3aa40-d2a7-11ed-b76b-3b279f6334bc.log >> -rw-r--r-- 1 cassandra cassandra 461 Apr 4 10:17 >> nb_txn_compaction_11433360-d265-11ed-b76b-3b279f6334bc.log >> -rw-r--r-- 1 cassandra cassandra 463 Apr 4 09:48 >> nb_txn_compaction_593e5320-d265-11ed-b76b-3b279f6334bc.log >> -rw-r--r-- 1 cassandra cassandra 614 Apr 3 22:47 >> nb_txn_compaction_701d62d0-d264-11ed-b76b-3b279f6334bc.log >> -rw-r--r-- 1 cassandra cassandra 136 Apr 3 22:27 >> nb_txn_compaction_bb770b50-d26e-11ed-b76b-3b279f6334bc.log >> -rw-r--r-- 1 cassandra cassandra 463 Apr 4 09:23 >> nb_txn_compaction_ce51bfe0-d264-11ed-b76b-3b279f6334bc.log >> -rw-r--r-- 1 cassandra cassandra 134 Apr 4 10:31 >> nb_txn_compaction_d17c7380-d2d3-11ed-b76b-3b279f6334bc.log >> -rw-r--r-- 1 cassandra cassandra 464 Apr 4 09:24 >> nb_txn_compaction_ed7fc650-d264-11ed-b76b-3b279f6334bc.log >> -rw-r--r-- 1 cassandra cassandra 613 Apr 3 22:54 >> nb_txn_compaction_f456f3b0-d271-11ed-b76b-3b279f6334bc.log >> >> Let's take for example the one from "Apr 4 09:24" >> I can see the matching log message in system.log >> >> INFO [CompactionExecutor:142085] 2023-04-04 09:24:29,892 >> CompactionTask.java:241 - Compacted (ed7fc650-d264-11ed-b76b-3b279f6334bc) >> 2 sstables to >> [/var/lib/cassandra/data/disk1/kt_ks/new_table-44263b406bf111ed8bd9df80ace3677a/nb-12142-big,] >> to level=0. 362.987GiB to 336.323GiB (~92% of original) in 43,625,742ms. >> Read Throughput = 8.520MiB/s, Write Throughput = 7.894MiB/s, Row Throughput >> = ~-11,482/s. 3,755,353,838 total partitions merged to 3,479,484,261. >> Partition merge counts were {1:3203614684, 2:275869577, } >> >> >> [user@server808 new_table-44263b406bf111ed8bd9df80ace3677a]# cat >> nb_txn_compaction_ed7fc650-d264-11ed-b76b-3b279f6334bc.log >> >> ADD:[/var/lib/cassandra/data/disk1/kt_ks/new_table-44263b406bf111ed8bd9df80ace3677a/nb-12142-big-,0,8][2633027732] >> >> REMOVE:[/var/lib/cassandra/data/disk1/kt_ks/new_table-44263b406bf111ed8bd9df80ace3677a/nb-10334-big-,1680543675071,8][4190572643] >> >> REMOVE:[/var/lib/cassandra/data/disk1/kt_ks/new_table-44263b406bf111ed8bd9df80ace3677a/nb-12109-big-,1680554352704,8][3101929253] >> COMMIT:[,0,0][2613697770] >> >> I would expect sstable 10334 to be gone, since compaction finished an >> hour ago, but files are still there. >> >> >> [user@server808 new_table-44263b406bf111ed8bd9df80ace3677a]# ls -l >> /var/lib/cassandra/data/disk1/kt_ks/new_table-44263b406bf111ed8bd9df80ace3677a/nb-10334-big-* >> -rw-r--r-- 1 cassandra cassandra 315582480 Mar 24 16:46 >> /var/lib/cassandra/data/disk1/kt_ks/new_table-44263b406bf111ed8bd9df80ace3677a/nb-10334-big-CompressionInfo.db >> -rw-r--r-- 1 cassandra cassandra 361124597166 Mar 24 16:46 >> /var/lib/cassandra/data/disk1/kt_ks/new_table-44263b406bf111ed8bd9df80ace3677a/nb-10334-big-Data.db >> -rw-r--r-- 1 cassandra cassandra 10 Mar 24 16:46 >> /var/lib/cassandra/data/disk1/kt_ks/new_table-44263b406bf111ed8bd9df80ace3677a/nb-10334-big-Digest.crc32 >> -rw-r--r-- 1 cassandra cassandra 4316334488 Mar 24 16:46 >> /var/lib/cassandra/data/disk1/kt_ks/new_table-44263b406bf111ed8bd9df80ace3677a/nb-10334-big-Filter.db >> -rw-r--r-- 1 cassandra cassandra 283651305837 Mar 24 16:46 >> /var/lib/cassandra/data/disk1/kt_ks/new_table-44263b406bf111ed8bd9df80ace3677a/nb-10334-big-Index.db >> -rw-r--r-- 1 cassandra cassandra 11934 Mar 24 16:46 >> /var/lib/cassandra/data/disk1/kt_ks/new_table-44263b406bf111ed8bd9df80ace3677a/nb-10334-big-Statistics.db >> -rw-r--r-- 1 cassandra cassandra 763353245 Apr 3 17:41 >> /var/lib/cassandra/data/disk1/kt_ks/new_table-44263b406bf111ed8bd9df80ace3677a/nb-10334-big-Summary.db >> -rw-r--r-- 1 cassandra cassandra 92 Mar 24 16:46 >> /var/lib/cassandra/data/disk1/kt_ks/new_table-44263b406bf111ed8bd9df80ace3677a/nb-10334-big-TOC.txt >> [user@server808 new_table-44263b406bf111ed8bd9df80ace3677a]# ls -l >> /var/lib/cassandra/data/disk1/kt_ks/new_table-44263b406bf111ed8bd9df80ace3677a/nb-12142-big-* >> -rw-r--r-- 1 cassandra cassandra 315582480 Apr 4 09:24 >> /var/lib/cassandra/data/disk1/kt_ks/new_table-44263b406bf111ed8bd9df80ace3677a/nb-12142-big-CompressionInfo.db >> -rw-r--r-- 1 cassandra cassandra 361124597166 Apr 4 09:24 >> /var/lib/cassandra/data/disk1/kt_ks/new_table-44263b406bf111ed8bd9df80ace3677a/nb-12142-big-Data.db >> -rw-r--r-- 1 cassandra cassandra 10 Apr 4 09:24 >> /var/lib/cassandra/data/disk1/kt_ks/new_table-44263b406bf111ed8bd9df80ace3677a/nb-12142-big-Digest.crc32 >> -rw-r--r-- 1 cassandra cassandra 4316334488 Apr 4 09:24 >> /var/lib/cassandra/data/disk1/kt_ks/new_table-44263b406bf111ed8bd9df80ace3677a/nb-12142-big-Filter.db >> -rw-r--r-- 1 cassandra cassandra 283651305837 Apr 4 09:24 >> /var/lib/cassandra/data/disk1/kt_ks/new_table-44263b406bf111ed8bd9df80ace3677a/nb-12142-big-Index.db >> -rw-r--r-- 1 cassandra cassandra 11934 Apr 4 09:24 >> /var/lib/cassandra/data/disk1/kt_ks/new_table-44263b406bf111ed8bd9df80ace3677a/nb-12142-big-Statistics.db >> -rw-r--r-- 1 cassandra cassandra 709470839 Apr 4 09:41 >> /var/lib/cassandra/data/disk1/kt_ks/new_table-44263b406bf111ed8bd9df80ace3677a/nb-12142-big-Summary.db >> -rw-r--r-- 1 cassandra cassandra 92 Apr 4 09:24 >> /var/lib/cassandra/data/disk1/kt_ks/new_table-44263b406bf111ed8bd9df80ace3677a/nb-12142-big-TOC.txt >> >> >> Disk space and du command shows the following : >> >> [user@server808 disk1]# df -h >> /dev/mapper/data_vg-cass_lv 7.0T 6.6T 411G 95% >> /var/lib/cassandra/data/disk1 >> [user@server808 disk1]# du . -h|grep T >> 6.6T ./kt_ks/new_table-44263b406bf111ed8bd9df80ace3677a >> 6.6T ./kt_ks >> 6.6T . >> >> >> If i run sstableutil to clean things up, df command still shows space as >> occupied, but now du shows reduction, and files appear in lsof output >> >> [user@server808 new_table-44263b406bf111ed8bd9df80ace3677a]# sstableutil >> -c -v kt_ks new_table >> Warning: Maximum heap size rounded up to 512 MB >> WARN 10:52:18,106 memtable_cleanup_threshold has been deprecated and >> should be removed from cassandra.yaml >> Cleaning up... >> [user@server808 new_table-44263b406bf111ed8bd9df80ace3677a]# df -h >> /dev/mapper/data_vg-cass_lv 7.0T 6.6T 432G 94% >> /var/lib/cassandra/data/disk1 >> [user@server808 new_table-44263b406bf111ed8bd9df80ace3677a]# ls -l *txn* >> ls: cannot access *txn*: No such file or directory >> [user@server808 disk1]# du . -h|grep T >> 3.8T ./kt_ks/new_table-44263b406bf111ed8bd9df80ace3677a >> 3.8T ./kt_ks >> 3.8T . >> >> >> lsof|grep deleted output contains many rows like this : >> >> LocalPool 38608 40310 cassandra 879r REG 253,3 >> 283651305837 4297002780 >> /var/lib/cassandra/data/disk1/kt_ks/new_table-44263b406bf111ed8bd9df80ace3677a/nb-10334-big-Index.db >> (deleted) >> LocalPool 38608 40310 cassandra 1061r REG 253,3 >> 361124597166 4297002778 >> /var/lib/cassandra/data/disk1/kt_ks/new_table-44263b406bf111ed8bd9df80ace3677a/nb-10334-big-Data.db >> (deleted) >> OptionalT 38608 40352 cassandra 879r REG 253,3 >> 283651305837 4297002780 >> /var/lib/cassandra/data/disk1/kt_ks/new_table-44263b406bf111ed8bd9df80ace3677a/nb-10334-big-Index.db >> (deleted) >> OptionalT 38608 40352 cassandra 1061r REG 253,3 >> 361124597166 4297002778 >> /var/lib/cassandra/data/disk1/kt_ks/new_table-44263b406bf111ed8bd9df80ace3677a/nb-10334-big-Data.db >> (deleted >> logback-4 38608 40439 cassandra 1061r REG 253,3 >> 361124597166 4297002778 >> /var/lib/cassandra/data/disk1/kt_ks/new_table-44263b406bf111ed8bd9df80ace3677a/nb-10334-big-Data.db >> (deleted) >> >> >> I will add that this cluster contains a single table with twcs. >> >> gil >> >> >> On Tue, Apr 4, 2023 at 10:14 AM Gil Ganz <gilg...@gmail.com> wrote: >> >>> Hey >>> I have a 4.0.7 cluster in which I see weird behavior. >>> I expect that once compaction finishes, the old sstables that were part >>> of the compaction set will be deleted, but it appears they are deleted much >>> later, thus causing space issues. >>> >>> For example this is what I have in the log, only one compaction >>> finished, which took as input 3 sstables, but I can see many sstables were >>> deleted afterwards: >>> >>> >>> INFO [CompactionExecutor:17344] 2023-04-04 04:39:07,345 >>> CompactionTask.java:241 - Compacted (489ddc80-d282-11ed-b4fb-d9d812cda140) >>> 3 sstables to >>> [/var/lib/cassandra/data/disk1/kt_ks/new_table-44263b406bf111ed8bd9df80ace3677a/nb-5685-big,] >>> to level=0. 140.672GiB to 134.554GiB (~95% of original) in 13,894,920ms. >>> Read Throughput = 10.367MiB/s, Write Throughput = 9.916MiB/s, Row >>> Throughput = ~-80,450/s. 1,425,146,188 total partitions merged to >>> 1,378,482,110. Partition merge counts were {1:1339149089, 2:32001964, >>> 3:7331057, } >>> INFO [NonPeriodicTasks:1] 2023-04-04 04:39:08,151 SSTable.java:111 - >>> Deleting sstable: >>> /var/lib/cassandra/data/disk1/kt_ks/new_table-44263b406bf111ed8bd9df80ace3677a/nb-5546-big >>> INFO [NonPeriodicTasks:1] 2023-04-04 04:39:09,399 SSTable.java:111 - >>> Deleting sstable: >>> /var/lib/cassandra/data/disk1/kt_ks/new_table-44263b406bf111ed8bd9df80ace3677a/nb-5424-big >>> INFO [NonPeriodicTasks:1] 2023-04-04 04:39:10,563 SSTable.java:111 - >>> Deleting sstable: >>> /var/lib/cassandra/data/disk1/kt_ks/new_table-44263b406bf111ed8bd9df80ace3677a/nb-5677-big >>> INFO [NonPeriodicTasks:1] 2023-04-04 04:39:12,143 SSTable.java:111 - >>> Deleting sstable: >>> /var/lib/cassandra/data/disk1/kt_ks/new_table-44263b406bf111ed8bd9df80ace3677a/nb-3360-big >>> INFO [NonPeriodicTasks:1] 2023-04-04 04:39:12,754 SSTable.java:111 - >>> Deleting sstable: >>> /var/lib/cassandra/data/disk1/kt_ks/new_table-44263b406bf111ed8bd9df80ace3677a/nb-5604-big >>> INFO [NonPeriodicTasks:1] 2023-04-04 04:39:13,328 SSTable.java:111 - >>> Deleting sstable: >>> /var/lib/cassandra/data/disk1/kt_ks/new_table-44263b406bf111ed8bd9df80ace3677a/nb-5572-big >>> INFO [NonPeriodicTasks:1] 2023-04-04 04:39:13,340 SSTable.java:111 - >>> Deleting sstable: >>> /var/lib/cassandra/data/disk1/kt_ks/new_table-44263b406bf111ed8bd9df80ace3677a/nb-5684-big >>> INFO [NonPeriodicTasks:1] 2023-04-04 04:39:13,363 SSTable.java:111 - >>> Deleting sstable: >>> /var/lib/cassandra/data/disk1/kt_ks/new_table-44263b406bf111ed8bd9df80ace3677a/nb-5630-big >>> INFO [NonPeriodicTasks:1] 2023-04-04 04:39:14,492 SSTable.java:111 - >>> Deleting sstable: >>> /var/lib/cassandra/data/disk1/kt_ks/new_table-44263b406bf111ed8bd9df80ace3677a/nb-4991-big >>> INFO [NonPeriodicTasks:1] 2023-04-04 04:39:16,338 SSTable.java:111 - >>> Deleting sstable: >>> /var/lib/cassandra/data/disk1/kt_ks/new_table-44263b406bf111ed8bd9df80ace3677a/nb-2537-big >>> INFO [NonPeriodicTasks:1] 2023-04-04 04:39:18,287 SSTable.java:111 - >>> Deleting sstable: >>> /var/lib/cassandra/data/disk1/kt_ks/new_table-44263b406bf111ed8bd9df80ace3677a/nb-4171-big >>> INFO [NonPeriodicTasks:1] 2023-04-04 04:39:21,467 SSTable.java:111 - >>> Deleting sstable: >>> /var/lib/cassandra/data/disk1/kt_ks/new_table-44263b406bf111ed8bd9df80ace3677a/nb-1767-big >>> >>> >>> Am I missing something about how/when sstables are deleted? Is there >>> something I can do to control when that delete happens? >>> >>> gil >>> >>