Основным хранилищем метрик у нас является cassandra, мы используем её уже более трех лет. Для всех предыдущих проблем мы успешно находили решение, используя встроенные средства диагностики кассандры.
В кассандре достаточно информативное логгирование (особенно на уровне DEBUG, который можно включить на лету), подробные метрики, доступные через JMX и богатый набор утилит (nodetool, sstable*).
Но недавно мы столкнулись с одной достаточно интересной проблемой, и нам пришлось серьезно поломать голову, почитать исходный код кассандры, чтобы разобраться, что происходит.
Началось все с того, что время отклика кассандры на чтение по одной из таблиц начало расти:
В логах при этом было пусто, никаких фоновых процессов (compactions) не было. Мы достаточно быстро заметили, что растет количество SSTable в таблице bunches (там мы храним значения метрик наших клиентов):
Причем, что это происходит только на трех серверах из 9:
Дальше мы долго тупили, гуглили и читали JIRA, но похожих багов не нашлось. Но время шло и нужно было найти хотя бы временное решение, так как время ответа росло практически линейно. Было решено сделать принудительный compaction таблицы bunches, но так как из документации не очевидно, на одной или на всех нодах начнется компактизация при nodetool compact, мы иницировали этот процесс через JMX.
Дело в том, что мы уже научены горьким опытом, что изменение compaction strategy через ALTER TABLE чревато запуском полного compactiton одновременно на всех нодах кластера. Тогда же нашелся способ делать это более управляемо.
На этот раз оказалось, что nodetool compact запускает compaction только на той ноде, с которой мы работаем.
После того, как закончилась компактизация, количество sstable снизилось, но сразу начало расти снова:
Таким образом у нас появился костыль, позволяющий в ручном режиме держать показатели работы кассандры на приемлемом уровне. Мы поставили принудительный compaction в крон на проблемных нодах, и график времени ответа на чтение стал выглядеть так:
В данный момент мы используем cassandra 2.1.15, но в JIRA обнаружили несколько похожих багов, исправленных в версиях 2.2+.
Так как хороших идей на тот момент не было, мы решили обновить одну из проблемных нод до 2.2 (тем более мы все равно собирались это делать и наше приложение уже было протестировано с 2.2). Обновление прошло гладко, но нашу проблему это не решило.
Чтобы не вносить дополнительной энтропии в текущую ситуацию, кластер целиком мы решили не обновлять и вернуться на 2.1 (это делается через удаление ноды из кластера и возвращеним обратно со старой версией).
Стало понятно, что с наскока эту проблему решить не удастся и пора идти читать код кассандры. Так как в этой таблице у нас в конечном счете хранятся timeseries, мы используем DateTieredCompactionStrategy со следуюшими настройками:
{
'class': 'org.apache.cassandra.db.compaction.DateTieredCompactionStrategy',
'base_time_seconds': '14400',
'max_sstable_age_days': '90'
}Это позволяет для нашего случая добиться, чтобы данные за один и тот же интервал времени лежали рядом и не перемешивались со старыми данными. В тоже время данные, старше 90 дней не должны компактиться вообще, это исключит ненужную нагрузку на диски, так как эти данные уже точно не будут меняться.
Появляется гипотеза: вдруг наши sstable не компактятся, потому что кассандра думает, что они старше 90 дней?
Время, на которое опирается кассандра — это внутренний таймстамп, который обязательно есть у каждой колонки. Кассандра либо проставляет текущий таймстамп при записи данных, либо он может быть задан клиентом:
INSERT INTO table (fld1, fld2) VALUES (val1, val2) USING TIMESTAMP 123456789;(мы не используем эту фичу).
При проверки метадаты всех sstable утилитой sstablemetadata, мы нашли аномальное значение таймстампа:
$ 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Но у вновь созданных sstable были абсолютно нормальные таймстампы, почему они не компактятся? В коде обнаружилось такое:
/**
* 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<SSTableReader>()
{
public int compare(SSTableReader o1, SSTableReader o2)
{
return Long.compare(o1.getMaxTimestamp(), o2.getMaxTimestamp());
}
}).getMaxTimestamp();
}Now в нашем случае:
$ date -d @5760529710388
Sat Dec 2 16:46:28 MSK 184513То есть еще 182 тысячи лет можно даже не надеяться на compaction:)
На каждом из трех проблемных серверов была одна "битая" sstable достаточно большого размера (60Gb, 160Gb и 180Gb). Самую "маленькую" из них сдвинули в сторону, потом через sstable2json получили человекочитаемый файлик размером 125Gb и начали его grep'ать. Выяснилось, что есть одна битая колонка (второстепенная метрика одного тестового проекта), которую можно смело удалить.
Стандартного способа удалить данные из sstable у кассандры не нашлось, но очень близка по смыслу утилита sstablescrub. Посмотрев Scrubber.java, стало понятно, что timestamp он не читает и сделать красивый патч достаточно сложно, мы сделали некрасивый:
--- 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;
}, где 226;4;eJlZUXr078;1472083200 ключ битой записи, который мы знаем в результате упражнений с sstable2json.
И это сработало!
Отдельно порадовало, что sstablescrub работает очень быстро, практически на скорости записи на диск. Так как sstable — это immutable структура, любые модификации создают новую sstable, то есть для scrub нужно обеспечить достаточный объем свободного места на дисках. Для нас это оказалось проблемой, пришлось делать scrub на другом сервере и копировать зачищенную sstable обратно на нужный сервер.
После зачистки битой записи, наша таблица начала компактиться сама.
Но на одной ноде мы заметили, что постоянно компактится одна достаточно увесистая sstable (сама с собой) размером больше 100Gb:
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, }Как только процесс заканчивался, она начинала компактиться опять, например график операций чтения по дискам выглядел так:
Тут видно как этот файлик мигрировал с ssd1 на ssd2 и обратно.
В логе так же была ошибка о нехватке места:
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')Но зачем вообще компактить 1 sstable? Пришлось разбираться, как вообще выбираются sstable для compaction в DateTieredCompactionStrategy:
- Берется список всех sstable для текущей таблицы;
- Исключаются sstable, участвующие в compaction прямо сейчас;
- Исключаются sstable, у которых максимальный таймстамп старше max_sstable_age_days;
- Оставшиеся группируются по минимальному таймстампу, начиная с самых свежих. В каждой из таких групп выбираются кандидаты согласно SizeTieredCompactionStrategy, причем для первого интервала (base_time_seconds) необходимо минимум min_threshold (в нашем случае 4) файлов, а для более старых достаточно и двух. Если кандидатов в пределах группы нет, группа пропускается. За один проход для компактизации выбирается одна самая "молодая" группа;
- Для выбранной группы sstable для компактизации прогнозируется размер результирующего файла (просто сумма всех исходных), если необходимого свободного места нет ни в одной data_file_directories, из группы исключается самый большой файл;
- Если в группе в итоге остался хотя бы 1 файл, запускается компактизация;
При уровне логгирования DEBUG стало видно, что в нашем случае:
- получилась группа на компактизацию из 3х файлов
- SizeTieredCompactionStrategy выбрала для слияния 2 файла из 3х
- Из-а нехватки места остался 1 кандидат, он и компактился по кругу
Я не берусь судить баг это или фича (может при использовании TTL есть необходимость компактить 1 файл), но нам нужно было это как-то разрулить. Мы решили, что нужно просто найти способ дать кассандре их закомпактить.
Мы используем серверы, в которых 2 sata диска и 2 ssd. Проблемы с местом у нас возникают на ssd, мы решили, что кандидаты для этой проблемной компактизации мы скопируем на диск, поставим линки на ssd, тем самым освободим место на ssd для результирующей sstable. Это сработало и компактизация на этой машине стала работать в обычном режиме.
На этом графике видно, как в процессе участвовал hdd2.
Итого
- Не разобрались мы только с тем, как в sstable попала запись с кривым таймстампом (отложим это до повторения, если оно будет конечно)
- Нужно подкрутить настройки DateTieredCompactionStrategy: понизить max_sstable_age_days до 10-30 дней, чтобы sstable не разростались до гигантских размеров (проще будет обеспечить буфер при манипуляциях с ними)
- Исходный код кассандры достаточно понятный и документированный
- На доступность нашего сервиса данная проблема влияния почти не оказала (подтормаживали несколько раз по 2-3 минуты)