How we fixed a compaction week in Cassandra / okmeter.io's blog

Our main repository of metrics is cassandra, we have been using it for more than three years. For all previous problems, we successfully found a solution using the built-in diagnostics tools for cassandra.

Cassandra has quite informative logging (especially at the DEBUG level, which can be enabled on the fly), detailed metrics available through JMX and a rich set of utilities (nodetool, sstable *).

But recently, we encountered one rather interesting problem, and we had to seriously break our brains, read the source code of cassandra to figure out what was going on.

It all started with the fact that the response time of Kassandra to read on one of the tables began to grow:

In this case, the logs were empty, there were no background processes (compactions). We noticed quickly enough that the number of SSTable in the bunches table is growing (there we store the values ​​of the metrics of our customers):

Moreover, this happens only on three servers out of 9:

Then we stupid for a long time, googled and read JIRA , but there were no similar bugs. But time passed and it was necessary to find at least a temporary solution, since the response time grew almost linearly. It was decided to force the compaction of the bunches table, but since the documentation is not obvious on one or all nodes the compaction will start with nodetool compact , we initiated this process through JMX.

The fact is that we have already learned through bitter experience that changing the compaction strategy through is ALTER TABLEfraught with launching a full compactiton simultaneously on all nodes of the cluster. Then there was a way to do this in a more manageable way.

This time, it turned out that nodetool compact runs compaction only on the node we are working with.

After the compactization ended, the amount of sstable decreased, but immediately began to grow again:

Thus, we got a crutch that allows us to manually keep the performance of cassandra at an acceptable level. We put a compaction compaction in crowns on problematic nodes, and the time line for the response to read began to look like this:

We are currently using cassandra 2.1.15, but in JIRA we found several similar bugs fixed in versions 2.2+.

Since there were no good ideas at that time, we decided to upgrade one of the problematic nodes to 2.2 (especially since we were going to do this anyway and our application was already tested with 2.2). The update went smoothly, but this did not solve our problem.

In order not to introduce additional entropy in the current situation, we decided not to update the entire cluster and return to 2.1 (this is done by removing the node from the cluster and returning it back with the old version).

It became clear that it would not be possible to solve this problem from scratch and it was time to go read the cassandra code. Since we ultimately store timeseries in this table, we use DateTieredCompactionStrategy with the following settings:

{
    'class': 'org.apache.cassandra.db.compaction.DateTieredCompactionStrategy', 
    'base_time_seconds': '14400', 
    'max_sstable_age_days': '90'
}

This allows for our case to ensure that the data for the same time interval lie nearby and do not mix with the old data. At the same time, data older than 90 days should not be compacted at all, this will eliminate unnecessary load on the drives, since this data will definitely not change.

There is a hypothesis: suddenly our sstable will not compact, because Cassandra thinks that they are older than 90 days?

The time on which the cassandra rests is the internal timestamp that every column must have. Kassandra either puts down the current timestamp when writing data, or it can be set by the client:

INSERT INTO table (fld1, fld2) VALUES (val1, val2) USING TIMESTAMP 123456789;

(we do not use this feature).

When checking all sstable Metadata utility sstablemetadata , we found an anomalous value timestamp of:

$ sstablemetadata /mnt/ssd1/cassandra/okmeter/bunches-3f892060ef5811e5950a476750300bfc/okmeter-bunches-ka-377-Data.db |head
SSTable: /mnt/ssd1/cassandra/okmeter/bunches-3f892060ef5811e5950a476750300bfc/okmeter-bunches-ka-377
Partitioner: org.apache.cassandra.dht.RandomPartitioner
Bloom Filter FP chance: 0.010000
Minimum timestamp: 1458916698801023
Maximum timestamp: 5760529710388872447

But the newly created sstable had absolutely normal timestamps, why don't they compact? The following was found in the code :

/**
 * Gets the timestamp that DateTieredCompactionStrategy considers to be the "current time".
 * @return the maximum timestamp across all SSTables.
 * @throws java.util.NoSuchElementException if there are no SSTables.
 */
private long getNow()
{
    return Collections.max(cfs.getSSTables(), new Comparator()
    {
        public int compare(SSTableReader o1, SSTableReader o2)
        {
            return Long.compare(o1.getMaxTimestamp(), o2.getMaxTimestamp());
        }
    }).getMaxTimestamp();
}

Now in our case:

$ date -d @5760529710388
Sat Dec  2 16:46:28 MSK 184513

That is, another 182 thousand years, you can not even hope for compaction :)

On each of the three problematic servers there was one “broken” sstable of a sufficiently large size (60Gb, 160Gb and 180Gb). The smallest of them was shifted to the side, then through sstable2json we got a 125Gb human-readable file and began to grep it. It turned out that there is one broken column (the secondary metric of one test project), which can be safely removed.

Cassandra did not find a standard way to remove data from sstable, but the sstablescrub utility is very close in meaning . Having looked at Scrubber.java , it became clear that he does not read the timestamp and it’s rather difficult to make a beautiful patch, we made it ugly:

--- a/src/java/org/apache/cassandra/db/compaction/Scrubber.java
+++ b/src/java/org/apache/cassandra/db/compaction/Scrubber.java
@@ -225,6 +225,11 @@ public class Scrubber implements Closeable
                     if (indexFile != null && dataSize != dataSizeFromIndex)
                         outputHandler.warn(String.format("Data file row size %d different from index file row size %d", dataSize, dataSizeFromIndex));
+                    if (sstable.metadata.getKeyValidator().getString(key.getKey()).equals("226;4;eJlZUXr078;1472083200")) {
+                        outputHandler.warn(String.format("key: %s", sstable.metadata.getKeyValidator().getString(key.getKey())));
+                        throw new IOError(new IOException("Broken column timestamp"));
+                    }
+
                     if (tryAppend(prevKey, key, dataSize, writer))
                         prevKey = key;
                 }

, where 226; 4; eJlZUXr078; 1472083200 is the key of the beat record, which we know as a result of exercises with sstable2json.

And it worked!
Separately, sstablescrub works very fast, almost at the speed of writing to disk. Since sstable is an immutable structure, any modifications create a new sstable, that is, scrub needs to provide sufficient free disk space. This turned out to be a problem for us, we had to do scrub on another server and copy the cleaned sstable back to the desired server.

After stripping the beat record, our table began to compact itself.

But on one note, we noticed that one fairly weighty sstable (with itself) larger than 100Gb is constantly compacting:

CompactionTask.java:274 - Compacted 1 sstables to [/mnt/ssd1/cassandra/okmeter/bunches-3f892060ef5811e5950a476750300bfc/okmeter-bunches-ka-5322,].  116,660,699,171 bytes to 116,660,699,171 (~100% of original) in 3,653,864ms = 30.448947MB/s.  287,450 total partitions merged to 287,450.  Partition merge counts were {1:287450, }

As soon as the process ended, it began to compact again, for example, the schedule of disk read operations looked like this:

Here you can see how this file migrated from ssd1 to ssd2 and vice versa.

There was also a lack of space error in the log:

CompactionTask.java:87 - insufficient space to compact all requested files SSTableReader(path='/mnt/ssd2/cassandra/okmeter/bunches-3f892060ef5811e5950a476750300bfc/okmeter-bunches-ka-2135-Data.db'), STableReader(path='/mnt/ssd1/cassandra/okmeter/bunches-3f892060ef5811e5950a476750300bfc/okmeter-bunches-ka-5322-Data.db')

But why bother compacting 1 sstable? I had to figure out how sstable for compaction in DateTieredCompactionStrategy is generally selected:

• A list of all sstable for the current table is taken;
• Excluded sstable participating in compaction right now;
• Excluded are sstable for which the maximum timestamp is older than max_sstable_age_days;
• The rest are grouped by the minimum timestamp, starting with the most recent. In each of these groups, candidates are selected according to SizeTieredCompactionStrategy , and for the first interval (base_time_seconds) you need a minimum of min_threshold (in our case 4) files, and for older ones, two are enough. If there are no candidates within the group, the group is skipped. In one pass, one of the "youngest" groups is selected for compaction;
• For the selected sstable group for compacting, the size of the resulting file is predicted (just the sum of all the source files), if there is no free space in any data_file_directories , the largest file is excluded from the group;
• If at least 1 file is left in the group, compactization starts;

При уровне логгирования DEBUG стало видно, что в нашем случае:

• получилась группа на компактизацию из 3х файлов
• SizeTieredCompactionStrategy выбрала для слияния 2 файла из 3х
• Из-а нехватки места остался 1 кандидат, он и компактился по кругу

Я не берусь судить баг это или фича (может при использовании TTL есть необходимость компактить 1 файл), но нам нужно было это как-то разрулить. Мы решили, что нужно просто найти способ дать кассандре их закомпактить.

Мы используем серверы, в которых 2 sata диска и 2 ssd. Проблемы с местом у нас возникают на ssd, мы решили, что кандидаты для этой проблемной компактизации мы скопируем на диск, поставим линки на ssd, тем самым освободим место на ssd для результирующей sstable. Это сработало и компактизация на этой машине стала работать в обычном режиме.

На этом графике видно, как в процессе участвовал hdd2.

Итого

• We did not understand only how the record with a curved timestamp got into sstable (we will postpone it until it repeats, if it will be finite)
• You need to tweak the DateTieredCompactionStrategy settings: lower max_sstable_age_days to 10-30 days so that sstable does not grow to gigantic sizes (it will be easier to provide a buffer when manipulating them)
• The source code of cassandra is quite clear and documented.
• This problem had almost no effect on the availability of our service (we slowed down several times for 2-3 minutes)