Время ожидания восстановления Кассандры в узле - PullRequest
Новая
       1

Время ожидания восстановления Кассандры в узле

0 голосов
/ 02 января 2019

Мы используем кластер Cassandra (3.10-1) с 5 узлами - каждый с 8 ядрами и памятью 23 Ги, все в одном DC.Коэффициент репликации - 2 Уровень согласованности - 2

В последнее время во время планового ремонта, который выполняется примерно раз в неделю, существует много тайм-аутов на запросы от одного узла - всегда один и тот же узел в разных ремонтах.Посмотрев на него журналы:

debug.log показывает, что при построении дерева Меркель для ремонта есть несколько ошибок. 

DEBUG [MemtablePostFlush:7354] 2018-12-30 23:52:08,314 ColumnFamilyStore.java:954 - forceFlush requested but everything is clean in user_device_validation_configuration
ERROR [ValidationExecutor:973] 2018-12-30 23:52:08,315 Validator.java:268 - Failed creating a merkle tree for [repair #b3887f60-0c8d-11e9-b894-754001cf0917 on keyspace1/user_device_validation_configuration, [(-8096630393642361664,-8073407512196669022]]], /10.52.5.42 (see log for details)
DEBUG [AntiEntropyStage:1] 2018-12-30 23:52:08,318 RepairMessageVerbHandler.java:114 - Validating ValidationRequest{gcBefore=1545349928} org.apache.cassandra.repair.messages.ValidationRequest@5c1c2b28
DEBUG [ValidationExecutor:973] 2018-12-30 23:52:08,319 StorageService.java:3313 - Forcing flush on keyspace keyspace1, CF raw_sensors
DEBUG [MemtablePostFlush:7354] 2018-12-30 23:52:08,319 ColumnFamilyStore.java:954 - forceFlush requested but everything is clean in raw_sensors
ERROR [ValidationExecutor:973] 2018-12-30 23:52:08,319 Validator.java:268 - Failed creating a merkle tree for [repair #b3887f60-0c8d-11e9-b894-754001cf0917 on keyspace1/raw_sensors, [(-8096630393642361664,-8073407512196669022]]], /10.52.5.42 (see log for details)
DEBUG [AntiEntropyStage:1] 2018-12-30 23:52:08,321 RepairMessageVerbHandler.java:114 - Validating ValidationRequest{gcBefore=1545349928} org.apache.cassandra.repair.messages.ValidationRequest@5c1c2b28
DEBUG [AntiEntropyStage:1] 2018-12-30 23:52:08,321 RepairMessageVerbHandler.java:142 - Got anticompaction request AnticompactionRequest{parentRepairSession=b387e320-0c8d-11e9-b894-754001cf0917} org.apache.cassandra.repair.messages.AnticompactionRequest@d4b7ed7b
ERROR [AntiEntropyStage:1] 2018-12-30 23:52:08,322 RepairMessageVerbHandler.java:168 - Got error, removing parent repair session
ERROR [AntiEntropyStage:1] 2018-12-30 23:52:08,322 CassandraDaemon.java:229 - Exception in thread Thread[AntiEntropyStage:1,5,main]
java.lang.RuntimeException: java.lang.RuntimeException: Parent repair session with id = b387e320-0c8d-11e9-b894-754001cf0917 has failed.
    at org.apache.cassandra.repair.RepairMessageVerbHandler.doVerb(RepairMessageVerbHandler.java:171) ~[apache-cassandra-3.10.jar:3.10]
    at org.apache.cassandra.net.MessageDeliveryTask.run(MessageDeliveryTask.java:66) ~[apache-cassandra-3.10.jar:3.10]
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[na:1.8.0_131]
    at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[na:1.8.0_131]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) ~[na:1.8.0_131]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0_131]
    at org.apache.cassandra.concurrent.NamedThreadFactory.lambda$threadLocalDeallocator$0(NamedThreadFactory.java:79) [apache-cassandra-3.10.jar:3.10]
    at java.lang.Thread.run(Thread.java:748) ~[na:1.8.0_131]
Caused by: java.lang.RuntimeException: Parent repair session with id = b387e320-0c8d-11e9-b894-754001cf0917 has failed.
    at org.apache.cassandra.service.ActiveRepairService.getParentRepairSession(ActiveRepairService.java:400) ~[apache-cassandra-3.10.jar:3.10]
    at org.apache.cassandra.service.ActiveRepairService.doAntiCompaction(ActiveRepairService.java:435) ~[apache-cassandra-3.10.jar:3.10]
    at org.apache.cassandra.repair.RepairMessageVerbHandler.doVerb(RepairMessageVerbHandler.java:143) ~[apache-cassandra-3.10.jar:3.10]
    ... 7 common frames omitted
DEBUG [ValidationExecutor:973] 2018-12-30 23:52:08,323 StorageService.java:3313 - Forcing flush on keyspace keyspace1, CF mouse_interactions
DEBUG [MemtablePostFlush:7354] 2018-12-30 23:52:08,323 ColumnFamilyStore.java:954 - forceFlush requested but everything is clean in mouse_interactions
ERROR [ValidationExecutor:973] 2018-12-30 23:52:08,327 Validator.java:268 - Failed creating a merkle tree for [repair #b3887f60-0c8d-11e9-b894-754001cf0917 on keyspace1/mouse_interactions, [(-8096630393642361664,-8073407512196669022]]], /10.52.5.42 (see log for details)
DEBUG [GossipStage:1] 2018-12-30 23:52:10,643 FailureDetector.java:457 - Ignoring interval time of 2000164738 for /10.52.3.47
DEBUG [GossipStage:1] 2018-12-30 23:52:13,643 FailureDetector.java:457 - Ignoring interval time of 2000239040 for /10.52.3.47
DEBUG [ReadRepairStage:407] 2018-12-30 23:52:15,133 ReadCallback.java:242 - Digest mismatch:
org.apache.cassandra.service.DigestMismatchException: Mismatch for key DecoratedKey(7486012912397474412, 000467657474000020376337363933643363613837616231643531633936396564616234636363613400) (a0e45fcd73255bcd93a63b15d41e0843 vs 7dff1a87a755cf62150befc8352f59e8)
    at org.apache.cassandra.service.DigestResolver.compareResponses(DigestResolver.java:92) ~[apache-cassandra-3.10.jar:3.10]
    at org.apache.cassandra.service.ReadCallback$AsyncRepairRunner.run(ReadCallback.java:233) ~[apache-cassandra-3.10.jar:3.10]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0_131]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0_131]
    at org.apache.cassandra.concurrent.NamedThreadFactory.lambda$threadLocalDeallocator$0(NamedThreadFactory.java:79) [apache-cassandra-3.10.jar:3.10]
    at java.lang.Thread.run(Thread.java:748) ~[na:1.8.0_131]
DEBUG [GossipStage:1] 2018-12-30 23:52:26,639 FailureDetector.java:457 - Ignoring interval time of 2000385682 for /10.52.3.47

После нескольких часов в журналах GC я заметил, что GCвызывается примерно каждые 20 секунд и останавливается более чем на 10 секунд при каждом вызове: 

2018-12-31T06:24:57.450+0000: 1184437.292: Total time for which application threads were stopped: 18.0318658 seconds, Stopping threads took: 0.0005000 seconds
2018-12-31T06:24:57.483+0000: 1184437.325: Total time for which application threads were stopped: 0.0053815 seconds, Stopping threads took: 0.0007325 seconds
2018-12-31T06:24:57.565+0000: 1184437.407: Total time for which application threads were stopped: 0.0118127 seconds, Stopping threads took: 0.0057652 seconds
2018-12-31T06:24:57.604+0000: 1184437.446: Total time for which application threads were stopped: 0.0064909 seconds, Stopping threads took: 0.0023037 seconds
2018-12-31T06:24:57.701+0000: 1184437.543: Total time for which application threads were stopped: 0.0066540 seconds, Stopping threads took: 0.0031299 seconds
{Heap before GC invocations=1377084 (full 108682):
 par new generation   total 943744K, used 943711K [0x00000005c0000000, 0x0000000600000000, 0x0000000600000000)
  eden space 838912K, 100% used [0x00000005c0000000, 0x00000005f3340000, 0x00000005f3340000)
  from space 104832K,  99% used [0x00000005f99a0000, 0x00000005ffff7ce0, 0x0000000600000000)
  to   space 104832K,   0% used [0x00000005f3340000, 0x00000005f3340000, 0x00000005f99a0000)
 concurrent mark-sweep generation total 7340032K, used 7340032K [0x0000000600000000, 0x00000007c0000000, 0x00000007c0000000)
 Metaspace       used 71629K, capacity 73844K, committed 75000K, reserved 1116160K
  class space    used 8521K, capacity 8909K, committed 9176K, reserved 1048576K
2018-12-31T06:24:58.029+0000: 1184437.870: [Full GC (Allocation Failure) 2018-12-31T06:24:58.029+0000: 1184437.871: [CMS: 7340032K->7340031K(7340032K), 15.2051822 secs] 8283743K->7443230K(8283776K), [Metaspace: 71629K->71629K(1116160K)], 15.2055451 secs] [Times: user=13.94 sys=1.28, real=15.20 secs] 
Heap after GC invocations=1377085 (full 108683):
 par new generation   total 943744K, used 103198K [0x00000005c0000000, 0x0000000600000000, 0x0000000600000000)
  eden space 838912K,  12% used [0x00000005c0000000, 0x00000005c64c7950, 0x00000005f3340000)
  from space 104832K,   0% used [0x00000005f99a0000, 0x00000005f99a0000, 0x0000000600000000)
  to   space 104832K,   0% used [0x00000005f3340000, 0x00000005f3340000, 0x00000005f99a0000)
 concurrent mark-sweep generation total 7340032K, used 7340031K [0x0000000600000000, 0x00000007c0000000, 0x00000007c0000000)
 Metaspace       used 71629K, capacity 73844K, committed 75000K, reserved 1116160K
  class space    used 8521K, capacity 8909K, committed 9176K, reserved 1048576K
}
2018-12-31T06:25:13.235+0000: 1184453.076: Total time for which application threads were stopped: 15.2103050 seconds, Stopping threads took: 0.0004204 seconds
2018-12-31T06:25:13.243+0000: 1184453.085: Total time for which application threads were stopped: 0.0047592 seconds, Stopping threads took: 0.0008416 seconds
2018-12-31T06:25:13.272+0000: 1184453.114: Total time for which application threads were stopped: 0.0085538 seconds, Stopping threads took: 0.0046376 seconds
2018-12-31T06:25:13.298+0000: 1184453.140: [GC (CMS Initial Mark) [1 CMS-initial-mark: 7340031K(7340032K)] 7536074K(8283776K), 0.0650538 secs] [Times: user=0.12 sys=0.01, real=0.06 secs] 
2018-12-31T06:25:13.364+0000: 1184453.206: Total time for which application threads were stopped: 0.0728487 seconds, Stopping threads took: 0.0039520 seconds
2018-12-31T06:25:13.364+0000: 1184453.206: [CMS-concurrent-mark-start]
{Heap before GC invocations=1377085 (full 108684):
 par new generation   total 943744K, used 943215K [0x00000005c0000000, 0x0000000600000000, 0x0000000600000000)
  eden space 838912K, 100% used [0x00000005c0000000, 0x00000005f3340000, 0x00000005f3340000)
  from space 104832K,  99% used [0x00000005f99a0000, 0x00000005fff7bd98, 0x0000000600000000)
  to   space 104832K,   0% used [0x00000005f3340000, 0x00000005f3340000, 0x00000005f99a0000)
 concurrent mark-sweep generation total 7340032K, used 7340031K [0x0000000600000000, 0x00000007c0000000, 0x00000007c0000000)
 Metaspace       used 71631K, capacity 73844K, committed 75000K, reserved 1116160K
  class space    used 8521K, capacity 8909K, committed 9176K, reserved 1048576K
2018-12-31T06:25:13.821+0000: 1184453.662: [Full GC (Allocation Failure) 2018-12-31T06:25:13.821+0000: 1184453.663: [CMS2018-12-31T06:25:16.960+0000: 1184456.802: [CMS-concurrent-mark: 3.592/3.596 secs] [Times: user=12.47 sys=0.38, real=3.60 secs]

Итак, я начал проверять разброс данных в кластере - мы используем num_of_tokens - 32 данные кажутся сбалансированными ~40% в каждом узле. 

UN  10.52.2.94  672.64 GiB  32           ?       ad3d1365-bbb7-4229-b586-40667ec22b41  rack1
UN  10.52.3.47  640.91 GiB  32           ?       cdba952b-9685-4769-aaf4-22e538a5c37f  rack1
UN  10.52.1.57  719.34 GiB  32           ?       13bb7573-eb30-489b-80c4-6e5a7c8e5f5e  rack1
UN  10.52.5.42  743.04 GiB  32           ?       c9e892c6-9281-4a49-b4c4-a147a387c3de  rack1
UN  10.52.4.43  691.1 GiB  32           ?       53e3724e-f5a9-46b1-b330-7bb542f15f90  rack1

Так что после проверки журналов в другом узле я не могу найти причину для этого тайм-аута в этом конкретном узле.Какие-нибудь мысли или идеи относительно того, почему это происходит снова и снова на одном и том же узле?

1 Ответ

0 голосов
/ 04 января 2019

Странно видеть это только на одном узле.Дважды проверьте, что конфиги одинаковы.В противном случае вы могли бы писать / запрашивать большой раздел, за который этот узел несет основную ответственность.

Коэффициент репликации - 2 Уровень согласованности - 2

В общем случае ремонт можетЭто приводит к проблемам с обслуживанием узлов, поскольку построение деревьев Merkle и потоковая передача данных требуют значительных ресурсовЗдесь я вижу две проблемы:

  1. Длинные паузы GC.
  2. Соотношение RF / CL, которое не позволяет ни одному узлу не работать.

Начиная с # 2, когда у вас RF = 2 и вам требуется 2 реплики для ответа на ваши запросы, вы, по сути, запрашиваете CONSISTENCY_ALL.Поэтому, если узел перегружен и не хватает ресурсов, ваши запросы не смогут завершиться.Если бы это был я, я бы увеличил RF до 3 и выполнил бы ремонт (при условии, что узлы имеют достаточную память).Другим вариантом будет запрос на уровне согласованности 1 (ОДИН), что, вероятно, в любом случае следует делать с RF = 2.

Кроме того, при диагностике проблем с запросом обычно помогаетувидеть фактический запрос (который вы не предоставили).В Cassandra чаще всего проблемы с запросами являются результатом запросов, которые не вписываются в спроектированную таблицу.

Что касается длинных пауз в GC, решить эту проблему сложнее.Есть старый билет Cassandra JIRA ( CASSANDRA-8150 ), в котором говорится об оптимальных настройках CMS Garbage Collector.Вы должны прочитать это.

На что настроено ваше MAX_HEAP?Я вижу, ваше новое поколение меньше 1 ГБ, что будет слишком мало.С 23 ГБ ОЗУ на каждом узле я бы начал со следующих настроек для использования CMS GC: * ​​1024 *

  • Максимальный размер кучи (Xmx) 8 ГБ-12 ГБ (вы хотите оставить около 50%ОЗУ для OS / page-cache).
  • Начальный размер кучи (Xms) равен максимальному размеру кучи, чтобы избежать снижения производительности при изменении размера кучи.
  • Новый размер кучи (Xmn) 40-50% от вашего максимального размера кучи (т.е. где-то между 3 ГБ-6 ГБ).Вам нужно много места для нового поколения.
  • MaxTenuringThreshold от 6 до 8, так как вы хотите, чтобы объекты передавались по пространствам выживших нового поколения до тех пор, пока они не умрут, вместо того, чтобы перейти в старое.поколения.По умолчанию, я думаю, что это значение равно 1, что означает, что объекты будут продвигаться слишком быстро.

По сути, продвижение от нового к старому / от старого к постоянному - это то, где происходят длинные паузы.В идеале вы хотели бы, чтобы все объекты в вашей куче создавались, жили и умирали в новом поколении, без поощрения .

В противном случае, возможно, стоит попробоватьиспользуя G1GC.Для G1 я бы выбрал Max / Initial Heap около 50% оперативной памяти, MaxGCPauseMillis 400-500 мс и вообще не устанавливал новый размер кучи (G1 вычисляет это).

Добро пожаловать на сайт PullRequest, где вы можете задавать вопросы и получать ответы от других членов сообщества.

Нет похожих вопросов

...