Active flows -> maxflows #8
Comments
|
10гбит мы не тестировали. Подумаю над вашими данными. Как я понял Natevents вы не используете (эту фичу я хочу удалить в будущем). Интересно "55.87% [kernel] [k] _raw_spin_lock" какой там stack trace. В git версии уже есть оптимизация для лучшего распараллеливания, но может её недостаточно, надо думать и смотреть, но к сожалению у меня настолько загруженного сервера нет. |
|
10Гбит - это суммарный траффик проходящий в обе стороны, т.е. на сервер с одной стороны пришло около 7-8 гбит, с другой стороны - 2-3. natevents не используем, пока руки не доходили до них. Если подскажете как посмотреть stack trace - с радостью покажу. Насколько я понял - до какого-то момента всё работало нормально, включение netflow добавляло процентов 10 нагрузки, однако при достижении 5,5-6Гбит, по мере дальнейшего роста полосы - загрузка в течение часа выросла с 40% до 100%, после чего netflow отключили. Попробую позже посмотреть не вернётся ли всё в норму при уменьшении количества трафика. |
|
Насчет perf, наилучших команд не скажу, но там на период, скажем пара сек, надо запустить |
|
Хм, сейчас совсем подругому выглядит: Ерунда какая-то.... Сходу perf record/report не осилил, завтра попробую разобраться. |
|
А, так и должно быть - это я hashsize не указал. С hashsize=4194304 и maxflows=8388608: |
|
Трафика около 8Гбит in+out: hashsize=65536 maxflows=2097152 Количество flow НЕ растёт, кушает при этом под 20-25% процессора. Перезагрузил модуль с hashsize=16384 maxflows=2097152 И active растёт дальше... Снова загрузил с hashsize=65536 maxflows=2097152 - Flows: active 625117, грузит примерно 20% CPU и НЕ растёт, зараза. Загружаю с hashsize=4194304 maxflows=8388608 (параметры, с которыми сегодня в ЧНН начался неконтролируемый рост active flows. В принципе - значения явно завышены, надо поделить как минимум на 2...исторически сложилось), получаю |
|
Предполагаю, что у вас статистика правильная. Согласно вашей статистике, у вас средняя длинна потока 19.7 и 28.6 пакетов, что, на мой взгляд, является нормальным для небольшого промежутка времени. MemTraf X pkt деленный на эту длину и даёт примерно столько потоков в памяти в данный момент. Rate X packets/sec деленная на эту длину дает сколько новых потоков у вас приходит в секунду (до 65к), при этом flow сидит в памяти минимум 15 (inactive timeout) секунд, то есть все это реально накапливается, до таких чисел. Большой трафик, плюс пиковая нагрузка. Эмпирически советую вам поставить hashsize от 10000000 и выше. И не снижать при последующих тестах. 27 и 8 значит хэш таблица используется крайне не эффективно - надо увеличивать пока не станет 1. |
Это я для теста значения брал, в порядке бреда. В нормальной работе у нас получается что-то около [1.10]. Не понятно почему при разных hashsize отличается количество active flow на сотни тысяч. Модуль перезагружал с интервалом в пару минут, так что трафик не сильно отличался. Четыре теста: hashsize=65536 maxflows=2097152 hashsize=16384 maxflows=2097152 hashsize=65536 maxflows=2097152 hashsize=4194304 maxflows=8388608 |
|
Насчет почему в conntrac -S меньше entries - другая логика хранения потоков - другие тайм-ауты. Можете поиграться с active/inactive timeouts, скажем сделать одинаковые по несколько сек (вплоть до 1) - количество потоков должно сократиться, но возрастёт трафик экспорта. |
|
hashsize не может влиять на кол-во active Flows, тут и думать не над чем. Это флуктуация. Маленькие значения hashsize зато сильно влияют на загрузку процессора. (Вы как-то сто проблем одновременно обсуждаете.) |
|
Хорошо, не буду упоминать про процессор. Причины различий между контреком и netflow понятны. Проблема в том, что в какой-то момент по непонятной причине active flow начинает расти вплоть до maxflows. Это тот же самый сервер что упомянут выше, с тем же самым трафиком. |
|
И ещё раз тот же сервер, но с другими параметрами hashsize: Как можно заметить - в первом случае |
|
Сервер тот же самый, но есть же колебания трафика. Обратите внимание, что у вас в первом случае packets/sec 580407, а во втором 1130918 в два раза больше. Очень много погрешности в данных - все равно что гадать по кофейной гуще.
Это интересно. |
|
Да, я обратил внимание и на различия в кол-ве пакетов. Уверяю вас, трафик при этом через сервер бегает примерно одинаковый +-100мбит, и реальное количество пакетов не меняется. |
|
Графики загрузки за день одного из ядер (остальные примерно одинаковы) Рост загрузки cpu примерно совпадает с началом роста кол-ва active flows, пики - попытки включить сбор netflow с разными параметрами. |
|
Подумаю на досуге как может hashsize влиять на кол-во потоков в памяти. По идее никак. Может быть там связь косвенная - маленький hashsize увеличивает нагрузку на процы, увеличивается latency, а это влияет на что-то ещё. |
Похоже. В первом traffic stat 90731776 пакетов во втором 39823650 - разница в два-три раза. Соотв., в первом в памяти учтено 89379489 пакетов, во втором 35855502. В обоих случаях средняя длинна потока ~35 пакетов. 89379489 / 33.51 = 2667248.25, реальная цифра 4194304 ~ в два раза больше. Природа IP трафика, что он очень неравномерный (там далеко не гауссово распределение и даже не пуассон). Плюс, кроме просто объема, у нас ещё играет роль длина потоков, что усложняет картину. ps. То что вы показываете какие-то картинки, это все усреднение по 5-15 минут. Если у вас будет огромная пила, но с циклом меньше 5 минут, то вы увидите на таком графике прямую линию. |
|
Я попробовал сделать hashsize меньше разумного (в версии 1.8), это не повлияло на кол-во активных потоков: |
|
Давайте уже исключим неравномерность трафика? Трафика стало заметно меньше (около 3гбит), так что при hashsize=8192 работает адекватно, так что пришлось взять ещё более неадекватное значение hashsize=256. Я охотно верю что у вас при небольшом количестве трафика проблема не проявляется, мы с ней тоже до данного момента ни разу не встречались. Однако - закономерность присутствует, и я совершенно не могу представить себе механизм, благодаря которому что-то может начинать неверно отрабатывать при малом значении hashsize. Как мне кажется, дело тут даже совершенно не в нём, однако при неадекватном значении оного, что-то начинает неверно отрабатывать и пакеты из одного потока перестают "склеиваться" в один flow в памяти. Собственно это видно по выводу данных из коллектора и tcpdump(точнее, вывода tcpdump там нету, поверьте на слово): http://forum.nag.ru/forum/index.php?showtopic=53979&st=200&gopid=928350&#entry928350 где один реальный поток пользователя виден в экспорте netflow как куча потоков с малым количеством пакетов. |
|
Взял последнюю версию из Git: Т.е. закономерность та же. Попробуем для текущего трафика (3гбита) найти hashsize при котором начинается неадекват: При hashsize=64 загрузка CPU 100%, при этом за 30 секунд просто не успело создаться более 293412 записей. |
|
Cпасибо за тест. Сколько была нагрузка на проц во время тестов? (Мне интересно было ли стабильно 100% при hashsize 256, если да, то причина может быть косвенной - максимальная нагрузка как-то влияет). "Поверьте на слово" - дело-то не в вере, а в сужении области поиска возможных проблем. У flowа много параметров, а по ссылке на nag отображены не все параметры, следовательно, никаких выводов сделать нельзя. "Реальный поток пользователя виден в экспорте netflow как куча потоков с малым количеством пакетов" - я такое наблюдал при низких значения таймаутов. "hashsize при котором начинается неадекват" - можете так же вывести значения нагрузки на проц(ы)? |
|
А вы не могли бы для этих тестов прислать мне полный лог статистики (ваш |
Таймауты были дефолтные - "active 1800, inactive 15". К сожалению более подробных логов не сохранилось. В принципе могу завтра попробовать повторить экперимент с tcpdump и отдельно взятым потоком. Такс, про процессор при hashsize=256. Загрузил модуль, подождал несколько минут: http://igorsd.ru/ipt_netflow/test.log |
|
Благодарю. |
|
Да это вам спасибо за помощь :) Попробую на завтра оставить с hashsize=8388608 maxflows=4194304, посмотрим, может поможет. Впрочем, в любом случае, было бы здорово понять в результате чего получается рост количества потоков и отловить это дело... |
|
Да, на всякий случай: Карточки по 6 прерываний на карту, каждое висит на своём ядре. Даж не знаю что ещё может пригодиться.... |
|
Судя по Дальше, но даже с меньшим трафиком, при Вот одну проблему выяснили: при слишком маленьком hashsize выходит нагрузка cpu 100% и экспорт замедляется увеличивая кол-во active flows. Решение тут - не допускать перенагрузки системы, чтоб никогда не было cpu 100%. Что полезно и чтоб избежать packet drops. |
|
Насчет вот этого
Логика экспорта отработана, наверняка там была нормальная ситуация, когда должен происходить экспорт по стандарту netflow. Условия такие:
Больше ни в каких случаях. |
Скорее всего так и есть. В целом оно так и должно быть по идее... Про дропы при 100% загрузке всё понятно, тут вопросов быть не может. Не понятно что причина, а что следствие. Пока мне кажется наиболее вероятным сценарием что при некотором стечении обстоятельств (недостаточный размер hashsize для текущего количества потоков), модуль в некоторых случаях генерит новые flow записи вместо использования существующих, в результате чего начинает расти нагрузка на CPU. С другой стороны не очень понятно как может быть несколько записей для одного потока, хотя, каюсь, я не программист, реализацию полностью не осилил. |
Это уже не важно. Таблица потоков постепенно увеличивается. Это увеличивает нагрузку, увеличение нагрузки замедляет экспорт, от этого таблица еще больше, а это еще сильнее увеличивает нагрузку. Порочный цикл. И так пока нагрузка не станет 100% и не начнутся дропы.
К сожалению я там ничего не понял что вы хотели ими сказать - на одном графике часы, на другом дни.
Может быть закон не линейный.
Новая запись возможна только если старая экспортнулась.
Нагрузка цпу из-за маленькой хэш таблицы, это закон природы. Желательно, чтоб хэш таблица была не менее двух раз больше кол-ва активных потоков. |
|
По #8 (comment) интерфейс seq_file - медленный. Чтоб его ускорить нужно сделать в nf_seq_debug_open() свой буфер размером, скажем, KMALLOC_MAX_SIZE и должно стать в десятки раз быстрее. Примерно так: Код аналогичный single_open_size(). |
Полумеры, чтоб выяснить в чем проблема? Не вижу чем это поможет.
Да задерживается экспорт. Теперь надо понять как и почему. |
Согласен. Возможно, из-за этого преждевременно обрывается экспорт. Хотя |
|
Добавил bedba68 дебаг строка маркеров - почему прекратился цикл экспорта в netflow_scan_and_export. Детальное описание в коммите. В обычном состоянии там должно быть
Покажите потом статистику аналогичную #8 (comment), но с нормальным состоянием тоже. |
|
Спасибо. Перезагружаю модуль и сразу смотрю: Вечером попробую снять статистику в момент возникновения проблем. |
|
Замечательно! Многовато Кстати, а какая у вас общая статистика (включая по процессорам)? В предыдущих постах, скажем #8 (comment), я видел огромные числа в метрике хеша ( |
|
|
Спс. |
Понял, почему не редко - из-за цикла. Надо подумать можно ли это (и/или ipt_netflow_list) реализовать вообще без локов или уменьшить concurrence. ps. Придумал заюзать llist и list_bl, но они есть только с 2011 года, с ядер 2.6.38 (list_bl) и 3.1 (llist), а мне желательно сохранить совместимость с 2.6.18 (centos5), минимум с 2.6.32 (centos6). Можете предложить свой вариант разгрузки локов если хотите. |
|
Боюсь у меня нет предложений - я всё же не программист а администратор :) |
|
Извиняюсь, что опять вмешиваюсь, но всё-таки позволю себе скапитанить.
А нельзя пока что просто реализовать код, и сделать его опциональным. А когда CentOS5 будет давно забыт, сделать этот код by default (сохранив старую реализацию в #ifdef-ах)? |
|
Пока поменял #define LOCK_COUNT (1<<8) на #define LOCK_COUNT (1<<16), соотв вместо 256 стало 65531 лок. Пока проблем с spin_trylock нету. До изменения: После: |
|
Впрочем, как и ожидалось, полностью это проблему решить не может, и иногда мы таки прерываемся по spin_trylock: |
После перезагрузки модуля: |
|
Под нагрузкой-то TTTTT? Вы так ни разу и не показали. |
|
Исправил проблему с trylock 60830da, потоки больше не должны накапливаться. Пожалуйста, постестируйте под нагрузкой. Если всё ок, то следующая проблема которая упоминалась и которая требует решения - снижение количества локов, для снижения нагрузки на процессор при огромном трафике (10Gbit). Проблему с локами/нагрузкой предлагаю обсуждать в отдельном тикете (#10), а то этот стал уже слишком большой и, в общем-то, этот тикет, в том виде как он заявлен - (должен быть уже) решён. А этот, если решение вас устраивает, закрыть. Спасибо за помощь! |
Так #8 (comment) - это и есть под нагрузкой. Собрал последнюю версию, запустил: Вечером посмотрим под нагрузкой. Вам спасибо! |
|
Пока вроде бы всё нормально, однако некоторое время назад нагрузка на процессоры как-то странно стала разделяться. Обратите внимание на drops и загрузку 3-го ядра: К сожалению, не отследил в какой момент это произошло. Видимо об этом и говорил dazgluk в #8 (comment) Распределение прерываний: Работа экспорта под нагрузкой: |
|
Оппа, пока писал - загрузка всех ядер ушла в 100%: |
|
После перезагрузки модуля: Где-то после 850тыс загрузка уходит в 100%. :( |
|
Поменял чуть-чуть вывод статистики: wk_count/trylock_success/trylock_failed #define LOCK_COUNT (1<<16) Итого. Мне кажется что проблему с экспортом мы полностью победили. Предлагаю проблему закрывать, и попытаться победить lock contention. |
|
Да решена. Проблема с нагрузкой не решалась. Пишите lock_stat в новый тикет. По поводу таких штук:
Нужно менять способ экспорта. Чтоб экспорт был не минимум 1/250 в секунду (ограничение schedule_delayed_work), а что-то более равномерное. Можно считать, что это четвертая проблема, которую надо решать (в новом тикете). Возможно даже, что решить эту проблему более важно чем lock contention. Создал тикет #11 на эту тему.
Вероятно сокет отказывается принимать такое количество данных, к сожалению вы не привели полной статистики - в данном случае по сокетам. Возможно там есть рост |
Добавил дамп всех потоков по мотивам вашего патча. dab2b4c Включается Так же есть опция Формат такой:
|
Thanks to hotid@github for prototype implementation (github issue #8). To enable: ./configure --enable-debugfs To view dump: cat /sys/kernel/debug/netflow_dump
Возникла проблема — при включении сбора netflow с ядром 3.12-0.bpo.1-amd64 (debian) наблюдаем странную картину — количество активных потоков быстро доходит до значения Maxflows (независимо от того что прописываем в Maxflows - если 2млн, то будет около 2млн active flows, если 5 - то около 5... и hashsize), при этом все ядра CPU загружаются на 100%.
Без включения модуля загрузка сервера около 45-55%.
Пробовал собирать gcc-4.6 и 4.7, версию из гита и пропатченую под 3.12 ядро версию 1.8 sf.net — поведение одинаковое.
Через пару минут после включения сбора netflow:
c hashsize=4194304 maxflows=8388608, времени проходит несколько больше, не стал дожидаться пока дойдёт до maxflows, но суть та же:
При этом
perf top с netflow:
perf top без netflow:
В контреке около 900 тыс записей, суммарный трафик проходящий через сервер — около 10гбит.
Подскажите, куда копать?
The text was updated successfully, but these errors were encountered: