Русский
Русский
English
Статистика
Реклама

Troubleshooting

Как траблшутить отечественный IPsec VPN. Часть 1

13.08.2020 14:10:01 | Автор: admin


Ситуация


Выходной. Пью кофе. Студент настроил VPN соединение между двумя точками и исчез. Проверяю: туннель действительно есть, но трафика в туннеле нет. На звонки студент не отвечает.

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


Исходные данные


Две территориально разделенные площадки связаны GRE туннелем. GRE нужно зашифровать:



Проверяю работоспособность GRE туннеля. Для этого запускаю ping с устройства R1 до GRE интерфейса устройства R2. Это целевой трафик для шифрования. Ответа нет:

root@R1:~# ping 1.1.1.2 -c 4
PING 1.1.1.2 (1.1.1.2) 56(84) bytes of data.

--- 1.1.1.2 ping statistics ---
4 packets transmitted, 0 received, 100% packet loss, time 3057ms


Смотрю логи на Gate1 и Gate2. Лог радостно сообщает, что IPsec туннель успешно поднялся, никаких проблем:

root@Gate1:~# cat /var/log/cspvpngate.log
Aug 5 16:14:23 localhost vpnsvc: 00100119 <4:1> IPSec connection 5 established, traffic selector 172.17.0.1->172.16.0.1, proto 47, peer 10.10.10.251, id "10.10.10.251", Filter
IPsec:Protect:CMAP:1:LIST, IPsecAction IPsecAction:CMAP:1, IKERule IKERule:CMAP:1


В статистике IPsec туннеля на Gate1 вижу, что туннель действительно есть, но счетчик Rсvd обнулен:

root@Gate1:~# sa_mgr show
ISAKMP sessions: 0 initiated, 0 responded

ISAKMP connections:
Num Conn-id (Local Addr,Port)-(Remote Addr,Port) State Sent Rcvd
1 3 (10.10.10.251,500)-(10.10.10.252,500) active 1070 1014

IPsec connections:
Num Conn-id (Local Addr,Port)-(Remote Addr,Port) Protocol Action Type Sent Rcvd
1 3 (172.16.0.1,*)-(172.17.0.1,*) 47 ESP tunn 480 0


Я траблшучу С-Терру так: ищу, где теряются целевые пакеты на пути от R1 до R2. В процессе (спойлер) найду ошибку.

Траблшутинг


Шаг 1. Что получает Gate1 от R1

Использую встроенный пакетный сниффер tcpdump. Запускаю сниффер на внутреннем (Gi0/1 в нотации Cisco-like или eth1 в нотации ОС Debian) интерфейсе:

root@Gate1:~# tcpdump -i eth1

tcpdump: verbose output suppressed, use -v or -vv for full protocol decode
listening on eth1, link-type EN10MB (Ethernet), capture size 262144 bytes
14:53:38.879525 IP 172.16.0.1 > 172.17.0.1: GREv0, key=0x1, length 92: IP 1.1.1.1 > 1.1.1.2: ICMP echo request, id 2083, seq 1, length 64
14:53:39.896869 IP 172.16.0.1 > 172.17.0.1: GREv0, key=0x1, length 92: IP 1.1.1.1 > 1.1.1.2: ICMP echo request, id 2083, seq 2, length 64
14:53:40.921121 IP 172.16.0.1 > 172.17.0.1: GREv0, key=0x1, length 92: IP 1.1.1.1 > 1.1.1.2: ICMP echo request, id 2083, seq 3, length 64
14:53:41.944958 IP 172.16.0.1 > 172.17.0.1: GREv0, key=0x1, length 92: IP 1.1.1.1 > 1.1.1.2: ICMP echo request, id 2083, seq 4, length 64


Вижу, что Gate1 получает от R1 GRE пакеты. Двигаюсь далее.

Шаг 2. Что Gate1 делает с GRE пакетами

Утилитой klogview смотрю, что происходит с GRE пакетами внутри VPN драйвера С-Терра:

root@Gate1:~# klogview -f 0xffffffff

filtration result for out packet 172.16.0.1->172.17.0.1, proto 47, len 112, if eth0: chain 4 "IPsecPolicy:CMAP", filter 8, event id IPsec:Protect:CMAP:1:LIST, status PASS
encapsulating with SA 31: 172.16.0.1->172.17.0.1, proto 47, len 112, if eth0
passed out packet 10.10.10.251->10.10.10.252, proto 50, len 160, if eth0: encapsulated


Вижу, что целевой GRE трафик (proto 47) 172.16.0.1 -> 172.17.0.1 попал (PASS) под правило шифрования LIST в криптокарте CMAP и зашифровался (encapsulated). Далее пакет смаршрутизировался (passed out). Ответного трафика в выводе klogview нет.

Проверяю списки доступа на устройстве Gate1. Вижу один список доступа LIST, который определяет целевой трафик для шифрования, значит правил МЭ не настроено:

Gate1#show access-lists
Extended IP access list LIST
10 permit gre host 172.16.0.1 host 172.17.0.1


Вывод: проблема не на устройстве Gate1.

Дополнительно о klogview
VPN драйвер обрабатывает весь сетевой трафик, не только тот, который должен шифроваться. Вот такие сообщение видны в klogview, если VPN драйвер обработал сетевой трафик и передал его в незашифрованном виде:

root@R1:~# ping 172.17.0.1 -c 4

root@Gate1:~# klogview -f 0xffffffff

filtration result for out packet 172.16.0.1->172.17.0.1, proto 1, len 84, if eth0: chain 4 "IPsecPolicy:CMAP": no match
passed out packet 172.16.0.1->172.17.0.1, proto 1, len 84, if eth0: filtered


Вижу, что ICMP трафик (proto 1) 172.16.0.1->172.17.0.1 не попал (no match) в правила шифрования криптокарты CMAP. Пакет смаршрутизировался (passed out) в открытом виде.

Шаг 3. Что получает Gate2 от Gate1

Запускаю сниффер на WAN (eth0) интерфейсе Gate2:

root@Gate2:~# tcpdump -i eth0
tcpdump: verbose output suppressed, use -v or -vv for full protocol decode
listening on eth0, link-type EN10MB (Ethernet), capture size 262144 bytes
16:05:45.104195 IP 10.10.10.251 > 10.10.10.252: ESP(spi=0x30088112,seq=0x1), length 140
16:05:46.093918 IP 10.10.10.251 > 10.10.10.252: ESP(spi=0x30088112,seq=0x2), length 140
16:05:47.117078 IP 10.10.10.251 > 10.10.10.252: ESP(spi=0x30088112,seq=0x3), length 140
16:05:48.141785 IP 10.10.10.251 > 10.10.10.252: ESP(spi=0x30088112,seq=0x4), length 140


Вижу, что Gate2 получает ESP пакеты от Gate1.

Шаг 4. Что Gate2 делает с ESP пакетами

Запускаю утилиту klogview на Gate2:

root@Gate2:~# klogview -f 0xffffffff
filtration result for in packet 10.10.10.251->10.10.10.252, proto 50, len 160, if eth0: chain 17 "FilterChain:L3VPN", filter 21, status DROP
dropped in packet 10.10.10.251->10.10.10.252, proto 50, len 160, if eth0: firewall


Вижу, что ESP пакеты (proto 50) были дропнуты (DROP), правилом (L3VPN) межсетевого экрана (firewall). Убеждаюсь, что к Gi0/0 действительно привязан список доступа L3VPN:

Gate2#show ip interface gi0/0
GigabitEthernet0/0 is up, line protocol is up
Internet address is 10.10.10.252/24
MTU is 1500 bytes
Outgoing access list is not set
Inbound access list is L3VPN


Проблему обнаружил.

Шаг 5. Что не так со списком доступа

Смотрю, что из себя представляет список доступа L3VPN:

Gate2#show access-list L3VPN
Extended IP access list L3VPN
10 permit udp host 10.10.10.251 any eq isakmp
20 permit udp host 10.10.10.251 any eq non500-isakmp
30 permit icmp host 10.10.10.251 any


Вижу, что разрешены ISAKMP пакеты, поэтому устанавливается IPsec туннель. А вот разрешающего правила для ESP нет. Видимо, студент перепутал icmp и esp.
Правлю список доступа:

Gate2(config)#
ip access-list extended L3VPN
no 30
30 permit esp host 10.10.10.251 any


Шаг 6. Проверяю работоспособность

Первым делом убеждаюсь, что список доступа L3VPN верный:

Gate2#show access-list L3VPN
Extended IP access list L3VPN
10 permit udp host 10.10.10.251 any eq isakmp
20 permit udp host 10.10.10.251 any eq non500-isakmp
30 permit esp host 10.10.10.251 any


Теперь с устройства R1 запускаю целевой трафик:

root@R1:~# ping 1.1.1.2 -c 4
PING 1.1.1.2 (1.1.1.2) 56(84) bytes of data.
64 bytes from 1.1.1.2: icmp_seq=1 ttl=64 time=35.3 ms
64 bytes from 1.1.1.2: icmp_seq=2 ttl=64 time=3.01 ms
64 bytes from 1.1.1.2: icmp_seq=3 ttl=64 time=2.65 ms
64 bytes from 1.1.1.2: icmp_seq=4 ttl=64 time=2.87 ms

--- 1.1.1.2 ping statistics ---
4 packets transmitted, 4 received, 0% packet loss, time 3006ms
rtt min/avg/max/mdev = 2.650/10.970/35.338/14.069 ms


Победа. GRE туннель установился. Счетчик входящего трафика в статистике IPsec не нулевой:

root@HUB2:~# sa_mgr show
ISAKMP sessions: 0 initiated, 0 responded

ISAKMP connections:
Num Conn-id (Local Addr,Port)-(Remote Addr,Port) State Sent Rcvd
1 3 (10.10.10.251,500)-(10.10.10.252,500) active 1474 1350

IPsec connections:
Num Conn-id (Local Addr,Port)-(Remote Addr,Port) Protocol Action Type Sent Rcvd
1 4 (172.16.0.1,*)-(172.17.0.1,*) 47 ESP tunn 1920 480


На шлюзе Gate2 в выводе klogview появились сообщения, что целевой трафик 172.16.0.1->172.17.0.1 успешно (PASS) расшифрован (decapsulated) правилом LIST в криптокарте CMAP:

root@Gate3:~# klogview -f 0xffffffff
filtration result for in packet 172.16.0.1->172.17.0.1, proto 47, len 112, if eth0: chain 18 "IPsecPolicy:CMAP", filter 25, event id IPsec:Protect:CMAP:1:LIST, status PASS
passed in packet 172.16.0.1->172.17.0.1, proto 47, len 112, if eth0: decapsulated


Итоги

Студент подпортил выходной.
Аккуратнее с правилами МЭ.

Анонимный инженер
t.me/anonimous_engineer
Подробнее..

Актуальность инициативы BAAG BattleAgainstAnyGuess

31.05.2021 06:09:55 | Автор: admin

14 лет назад, в июне 2007го, Алекс Горбачев, в то время еще CTO Pythian, основал BAAG Party - Battle Against Any Guess - инициативу против любых гаданий при решении технических проблем. Уже тогда это становилось большой проблемой: все чаще на форумах и публичных мейл-листах на вопросы о специфических проблемах, вместо запроса необходимых технических деталей, приходили ответы в духе "а попробуйте то, если не поможет - попробуйте это", "я когда-то видел похожее, мне помогло XXX", "а мне ХХХ не помогло, зато помогло YYY". Рождались различные мифы и порождали еще большее новых, оттуда и всякое "шаманство" и "танцы с бубном"(частично и "работает - не трожь"). Все это вполне объяснимо: сложность ПО и железа экспоненциально увеличивается; количество недостоверной информации а-ля "for dummies" в сети растет как снежный ком; IT отрасли нужно все больше и больше работников на "конвейеры" - "бери больше, кидай дальше". Появление #BAAG тогда было абсолютно закономерным и неотвратимым, но насколько она актуальна сейчас? Почему после ее расцвета и популярности в течение нескольких лет, она в забвении? Что и когда должно появиться ей на замену на данный период развития IT?

Для начала я хотел бы процитировать отрывок из интервью Алекса:

Whats wrong with making an educated guess? We have limited data, limited knowledge, limited experience, limited tools, and limited time. Can we ever really know?

Yes we can! At least, we should strive to know....
Most real life problems can be solved with the knowledge that is available in the public domain, using data that is possible to extract by applying the right experience and tools and taking enough time to do the job properly.
It is the purpose of the Battle to promote the importance of knowledge fighting ignorance, selecting the right tools for the job, popularizing the appropriate troubleshooting techniques, gaining experience, and learning to take time to diagnose the issue before applying the solution. One might think that the BAAG motto is a bit extreme but thats a political decision to emphasize the importance of the goal.
...
When I established the Battle Against Any Guess Party, a number of people argued that guesswork is the cruel reality with Oracle databases because sometimes we do hit the wall of the unknown. The argument is that at such point, there is nothing else left but to employ guesswork. Several times people have thrown out the refined term educated guess. However, I would argue that even in these cases, or especially in these cases, we should be applying scientific techniques. Two good techniques are deduction and induction.

Мой вольный перевод:

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

Да, мы можем! По крайней мере, мы должны пытаться. Большинство реальных проблем могут быть решены с помощью публично-доступных знаний и данных, которые можно получить, применяя правильные средства, опыт и достаточное время, чтобы сделать свою работу как следует. В этом и есть цель BAAG - продвижение важности знаний выбора правильных средств, популяризация соответствующих методов траблшутинга, получение опыта и обучение диагностике. Кто-то может сказать, что девиз BAAG чересчур категоричный, но это было сделаано нарочно, чтобы подчеркнуть важность цели. Когда я основал BAAG, множество людей утверждало, что гадания - это жестокая реальность при работе Oracle, т.к. иногда мы бьемся о стену неизвестности, т.е. в определенный момент не остается ничего, кроме как гадать. Несколько раз люди бросались термином "обоснованное предположение". Тем не менее, я считаю, что даже в таких случаях, или особенно в таких случаях, мы должны придерживаться научных подходов, например: дедукции и индукции.

Времена меняются: так же как и когда-то прошло время энциклопедистов, придет время и в IT, когда объем необходимых знаний даже для траблшутинга от верхнеуровневых процедур до сисколлов ядра превысит критическую точку. Все еще осложняется тем, что количество качественной достоверной информации относительно низкосортной писанины неуклонно уменьшается. Типичная ситуация сейчас: человека встречает проблему, гуглит ее, приходит на какой-нибудь стековерфлоу и берет решение из ответа, помеченного как правильный. Ладно еще, если это помогло, а если не помогло, то начинается перебор - вторая ссылка, третья ссылка, и тд, или создается новый вопрос и тогда перебор по ответам... Какова же вероятность выбора оптимального решения в таких случаях? Или даже проще: являются ли люди из топа по ответам экспертами в областях, в которых они отвечают? Не будет ли порожден очередной миф? Причем, я одобряю и полностью поддерживаю терпение, широту знаний и любознательность таких энтузиастов! IT уже давно не удел только энтузиастов, теперь полно людей, которые не любят свою работу, и их палкой не заставить что-то прочитать, или сотрудников загоняют настолько, что у них просто не остается ни времени, ни сил на самообразование.

В сложившейся ситуации, очевидно, что от гаданий и метода проб и ошибок уже никуда не деться. Так может уже уйти от категоричного Battle Against Any Guess, к чему-то более терпимому? Например, Battle Against Any Non-educated Guess или на худой конец Guess Carefully? Или уже смириться с этим и просто надеяться на светлое будущее? Ведь в целом, несмотря на всю печальность ситуации и страшные (но уже набившие оскомину) аналогии с врачами, все не так страшно: проблемы так или иначе решаются, а в сложных критичных областях все намного серьезнее и уже так не гадают...

Подробнее..

Стабильная нестабильность оксиморон или необходимость?

19.04.2021 12:12:03 | Автор: admin

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

Краткое вступление

Я часто занимаюсь поиском неисправностей в IT системах сложности от средней и выше. Ещё это иногда называют troubleshooting. Хотя иногда переходят на личности и даже обзывают бездельником. Перегрузи хост и дело сделано, говорят мне некоторые коллеги. Я поначалу удивлялся, как можно такое предложить, если на хосте крутится куча сервисов, иногда критических, если куча разработчиков родила массу процессов и хост является частью большой системы!? Потом перестал. И вот почему...

No RebootNo Reboot

В IT сфере бушует индустриализация. Ничего плохого в этом нет и даже иногда это оправдано. Разделение труда, планирование и т.п. - отлично. Проблема в том, что индустриальная эпоха спровоцировала появление в IT большого количества узких специалистов, которые не имеют широгоко взгляда на задачу/систему, которую они разрабатывают или обслуживают. Они в этом не виноваты и обличать никого не собираюсь, все усилия направлены на поиск причины и решения проблемы. Я убеждён, что специалис должен иметь "широкий взгляд на мир" и на ряду с основной специализацией хотябы поверхносто понимать соседние области. Я называю таких allrounder или "мультинструменталистами" (муз. - играющими на разных инструменах)

Но давайте перейдём от макроэкономики и психологии к технике и я попытаюсь обосновать, почему не стоит просто ребутить сервера. Примем как аксиому, что система изначально работала хорошо и выполняла свои функции. Т.е. была в стабильном состоянии. Тут стоит уточнить и определить как минимум 3 возможных состояния системы:

  • стабильное (всё работает как надо)

  • метастабильное (работает, но по принципу "never touch a running system")

  • нестабильное (всё плохо)

Нормально работающие системы находятся либо в стабильном, либо на худой конец (и чаще всего) в метастабильном состояниях.

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

Здесь я введу ещё два важных термина. Состояния системы, как подмножество нестабильного:

  • стабильно нестабильное (или устойчиво нестабильное)

  • нестабильно нестабильное

Стабильно нестабильное или устойчиво нестабильное состояние системы

Самый важный момент. Мы точно знаем, что система работает не так, как надо, но не знаем почему. В этом состоянии у нас есть возможность посмотреть логи, поговорить с "людьми" (разрабами, прорабами, сетевиками и пользователями), накопить наблюдения для дальнейших суждений и выводов. Главное - не дестабилизировать стабильно нестабильную систему! Это мой слоган на данном этапе. Самый основной и любимый способ дестабилизации или другими словами, перевода системы в нестабильно нестабильное состояние - ребут.

Простой пример из жизни. Система работала со сбоями. После многочисленных ребутов проблема пропадала и мне ставили на вид, мол помогает, а ты нам тут сказки рассказываешь. Правда заодно появлялись странные артефакты в виде подвисания клиентских сессий и пропадания данных (иногда). Проблема спорадически появлялась снова с снова в самый неприятный момент, обычно на выходных. Оказалось, что накосячили с ротацией логов и диск переполнялся. При ребуте временный раздел освобождался и всё какое-то время как-то работало. Пока он снова не переполнялся. Мониторить этот раздел конечно забыли. Элементарно подправили алгоритм ротации логов. За 5 минут где-то. Есть масса более сложных случаев в больших системах с кучей серверов и сервисов, но не буду засорять эфир, смысл думаю понятен.

Нужно чётко понимать основную цель troubleshooting - определить источник вывода системы из равновесия и вернуть её в стабильное состояние. Часто же просходит неверная интерпретация. Многие боятся признаться в ошибке, а иногда даже пытаются её скрыть. Тут нужно добавить, что ответственные за систему тоже иногда пытаются найти или даже назначить виноватого. Это всё сильно вредит общему делу. Выходит, что без психологии в поиске неисправностей никак не обойтись. Что подтвержнает мой тезис о "мультиниструменталистах" во вступлении.

Подведём итоги. Для успехов в поиске неисправностей надо:

  • быть смелым и признаваться в своих ошибках. Это 50% успеха на пути к цели

  • удерживать нестабильную систему в стабильно нестабильном состоянии

  • искать неисправность

Всё, как в жизни :-)

Я "по верхам" (high level) пробежал по теории поиска неисправностей и высветил только её один аспект. Если будет интерес, могу углубиться в другие. Всем спасибо.

Подробнее..

Перевод Post Mortem по недоступности Quay.io

21.08.2020 10:13:31 | Автор: admin
Прим. перев.: в начале августа Red Hat публично рассказала о решении проблем доступности, что возникали в предыдущие месяцы у пользователей её сервиса Quay.io (в его основе реестр для образов контейнеров, доставшийся компании вместе с покупкой CoreOS). Вне зависимости от вашей заинтересованности в этом сервисе как таковом, поучителен сам путь, по которому прошли SRE-инженеры компании для диагностики и устранения причин аварии.



19 мая, ранним утром (по летнему североамериканскому восточному времени, EDT), сервис quay.io упал. Авария затронула как потребителей quay.io, так и Open Source-проекты, использующие quay.io в качестве платформы для сборки и распространения ПО. Red Hat дорожит доверием как одних, так и других.

Команда SRE-инженеров сразу подключилась к работе и постаралась как можно скорее стабилизировать работу сервиса Quay. Однако пока они этим занимались, клиенты лишились возможности pushить новые образы, и лишь периодически им удавалось pullить имеющиеся. По неведомой причине база данных quay.io блокировалась после масштабирования сервиса на полную мощность.

Что изменилось? это первый вопрос, который принято задавать в подобных случаях. Мы заметили, что незадолго до проблемы кластер OpenShift Dedicated (на котором работает quay.io) начал обновляться до версии 4.3.19. Поскольку quay.io работает на Red Hat OpenShift Dedicated (OSD), регулярные обновления были обыденной операцией и никогда не приводили к проблемам. Более того, за предыдущие полгода мы несколько раз обновляли кластеры Quay без каких-либо перерывов в обслуживании. Пока мы пытались восстановить работу сервиса, другие инженеры начали готовить новый кластер OSD с предыдущей версией ПО, чтобы в случае чего развернуть все на нем.

Анализ первопричин


Основным симптомом сбоя была лавина из десятков тысяч подключений к БД, из-за которой экземпляр MySQL оказался фактически недееспособным. Из-за этого было сложно диагностировать проблему. Мы установили ограничение на максимальное количество подключений от клиентов, чтобы помочь команде SRE оценить проблему. Никакого необычного трафика к базе данных не заметили: на самом деле, большинство запросов были на чтение, а лишь немногие на запись.

Мы также попытались выявить паттерн в трафике БД, который мог бы вызвать эту лавину. Однако никаких закономерностей в логах отыскать не удалось. Ожидая готовности нового кластера с OSD 4.3.18, мы продолжали попытки запустить pod'ы quay.io. Каждый раз, когда кластер выходил на полную мощность, база данных зависала. Это означало, что было необходимо перезапустить экземпляр RDS в дополнение ко всем pod'ам quay.io.

К вечеру мы стабилизировали сервис в режиме read-only и отключили максимум несущественных функций (например, сбор мусора в пространстве имен), чтобы снизить нагрузку на БД. Зависания прекратились, но причина так и не была найдена. Новый кластер OSD был готов, и мы перенесли сервис, подключили трафик и продолжили мониторинг.

Quay.io стабильно работал на новом OSD-кластере, поэтому мы вернулись к логам базы данных, но так и не смогли обнаружить корреляцию, объясняющую блокировки. Инженеры OpenShift работали совместно с нами, пытаясь понять, могли ли изменения в Red Hat OpenShift 4.3.19 привести к проблемам с Quay. Однако ничего обнаружить не удалось, а воспроизвести проблему в лабораторных условиях не получилось.

Второй сбой


28 мая, незадолго до полудня по EDT, quay.io опять упал c тем же симптомом: функционирование базы данных блокировалось. И снова мы бросили все силы на расследование. Прежде всего было нужно восстановить работу сервиса. Однако на этот раз перезагрузка RDS и перезапуск pod'ов quay.io ни к чему не привели: очередная лавина подключений захлестнула базу. Но почему?

Quay написан на Python, и каждый pod работает как единый монолитный контейнер. В среде выполнения контейнера одновременно выполняется множество параллельных задач. Мы используем библиотеку gevent под gunicorn для обработки веб-запросов. Когда в Quay поступает запрос (через наш собственный API, или через API Docker'а), ему назначается gevent worker. Обычно этот worker должен связаться с базой данных. После первого сбоя мы обнаружили, что gevent worker'ы подключались к базе данных, используя настройки по умолчанию.

Учитывая значительное число pod'ов Quay и тысячи поступающих запросов в секунду, большое число подключений к базе данных теоретически могло перегрузить экземпляр MySQL. Благодаря мониторингу было известно, что Quay в среднем обрабатывает 5 тыс. запросов в секунду. Примерно таким же было и число подключений к базе данных. 5 тыс. подключений с запасом укладывались в возможности нашего экземпляра RDS (чего нельзя сказать о десятках тысяч). По какой-то причине происходили неожиданные всплески числа подключений, однако мы не замечали какой-либо корреляции со входящими запросами.

В этот раз мы твердо решили найти и устранить источник проблемы, а не ограничиться перезагрузкой. В кодовую базу Quay были внесены изменения, лимитирующие число подключений к БД для каждого worker'а gevent. Это число стало параметром в конфигурации: стало возможным менять его на лету, не собирая новый образ контейнера. Чтобы узнать, какое число подключений реально обработать, было проведено несколько испытаний со staging-окружением, в которых задавались разные значения, чтобы посмотреть, как это отразится на сценариях нагрузочного тестирования. В итоге обнаружилось, что Quay начинает выдавать ошибки 502, когда число подключений превышает 10 тыс.

Мы сразу развернули эту новую версию в production и стали следить за графиком подключений к базе данных. В прошлом база блокировалась примерно через 20 минут. Спустя 30 беспроблемных минут у нас появилась надежда, а спустя час уверенность. Мы восстановили трафик на запись на сайте и приступили к postmortem-анализу.

Сумев обойти проблему, приводящую к блокировке, мы не выяснили ее подлинные причины. Подтвердилось, что она не связана с какими-либо изменениями в OpenShift 4.3.19, поскольку то же самое случилось и на версии 4.3.18, которая до этого работала с Quay без каких-либо проблем. В кластере явно скрывалось что-то еще.

Детальное изучение


Quay.io шесть лет использовал настройки по умолчанию для подключения к БД без каких-либо проблем. Что изменилось? Понятно, что все это время трафик на quay.io неуклонно рос. В нашем случае все выглядело так, словно достигалось некое пороговое значение, которое служило триггером для лавины подключений. Мы продолжили изучать логи БД после второго сбоя, но не обнаружили каких-либо закономерностей или очевидных взаимосвязей.

Тем временем команда SRE занималась повышением наблюдаемости запросов Quay и общего здоровья сервиса. Были развернуты новые метрики и панели мониторинга, показывающие, какие части Quay пользуются наибольшим спросом со стороны клиентов.

Quay.io нормально работал до 9 июня. Утром (по EDT) мы снова стали свидетелями значительного увеличения числа подключений к базе данных. На этот раз простоя не случилось, поскольку новый параметр ограничивал их количество и не позволял превысить пропускную способность MySQL. Однако примерно в течение получаса многие пользователи отмечали медленную работу quay.io. Мы быстро собрали все возможные данные, воспользовавшись добавленными инструментами мониторинга. Внезапно проявилась закономерность.

Перед самым скачком числа подключений большое число запросов поступило на App Registry API. App Registry это малоизвестная функция quay.io. Она позволяет хранить такие штуки, как чарты Helm и контейнеры с богатыми (rich) метаданными. Большинство пользователей quay.io не работают с этой функцией, однако ей активно пользуется Red Hat OpenShift. OperatorHub в составе OpenShift хранит все операторы в App Registry. Эти операторы формируют основу для экосистемы рабочих нагрузок OpenShift и операционной модели (в рамках операций второго дня, Day 2), ориентированной на партнеров.

Каждый кластер OpenShift 4 использует операторы из встроенного OperatorHub'а для публикации каталога операторов, доступных для установки, и предоставления обновлений для уже установленных. С ростом популярности OpenShift 4 увеличилось и число кластеров на нем по всему миру. Каждый из этих кластеров загружает содержимое операторов, чтобы запустить встроенный OperatorHub, используя App Registry внутри quay.io как бэкэнд. В поисках источника проблемы мы упустили то, что с постепенным ростом популярности OpenShift увеличивалось и давление на одну из редко используемых функций quay.io.

Мы провели некоторый анализ трафика запросов App Registry и заглянули в код реестра. Сразу же вскрылись недостатки, из-за которых запросы к базе данных формировались неоптимально. При небольшой нагрузке они не причиняли никаких хлопот, однако при ее возрастании становились источником проблем. У App Registry оказалось два проблемных endpoint'а, плохо реагирующих на возрастание нагрузки: первый выдавал список всех пакетов в репозитории, второй возвращал все blob'ы для пакета.

Устранение причин


Всю следующую неделю мы занимались оптимизацией кода самого App Registry и его окружения. Были переработаны явно неэффективные SQL-запросы, устранены лишние вызовы команды tar (она запускалась при каждом извлечении blob'ов), добавлено кэширование везде, где возможно. Затем было проведено масштабное тестирование производительности и сравнена скорость работы App Registry до и после изменений. Запросы API, которые раньше занимали до полуминуты, теперь выполнялись за миллисекунды. На следующей неделе мы развернули изменения в production, и с тех пор quay.io работает стабильно. За это время наблюдались несколько резких всплесков трафика на endpoint'е App Registry, но проделанные усовершенствования предотвратили перебои в работе базы данных.

Чему мы научились?


Понятно, что любой сервис старается избежать простоев. В нашем случае мы верим, что недавние сбои помогли сделать quay.io лучше. Для себя мы вынесли несколько основных уроков, которыми хотим поделиться:

  1. Данные о том, кто и как использует ваш сервис, не бывают лишними. Поскольку Quay просто работал, у нас никогда не возникала необходимость тратить время на оптимизацию трафика и управление нагрузкой. Все это создало ложное ощущение безопасности, что сервис может масштабироваться до бесконечности.
  2. Когда сервис падает, восстановление его работы главный приоритет. Поскольку Quay продолжал страдать от заблокированной базы данных во время первого сбоя, наши стандартные процедуры не оказали предполагаемого эффекта и мы не смогли восстановить работу сервиса с их помощью. Это привело к ситуации, когда пришлось тратить время на анализ и сбор данных в надежде найти первопричину вместо того, чтобы направить все усилия на восстановление работоспособности.
  3. Оценивайте влияние каждой из функций сервиса. Клиенты редко использовали App Registry, поэтому он не являлся приоритетным для нашей команды. Когда некоторые функции продукта почти не используются, их баги всплывают редко, и разработчики перестают следить за кодом. Легко стать жертвой заблуждения, что так и должно быть пока внезапно эта функция не оказывается в центре масштабного инцидента.

Что дальше?


Работа по обеспечению стабильности сервиса никогда не прекращается и мы постоянно улучшаем его. Объемы трафика на quay.io продолжают расти, и мы осознаем, что обязаны делать все возможное, чтобы оправдать доверие клиентов. Поэтому в настоящее время работаем над следующими задачами:

  1. Развертывание реплик баз данных только для чтения, чтобы помочь сервису обрабатывать соответствующий трафик в случае возникновения проблем с основным экземпляром RDS.
  2. Обновление экземпляра RDS. Текущая версия сама по себе не является проблемой. Скорее, мы просто хотим убрать ложный след (по которому пошли во время сбоя); поддержание ПО в актуальном состоянии позволит устранить еще один фактор на случай будущих отключений.
  3. Дополнительное кэширование по всему кластеру. Мы продолжаем поиск областей, в которых кэширование позволить снизить нагрузку на базу данных.
  4. Добавление firewallа веб-приложений (WAF), чтобы видеть, кто и почему подключается к quay.io.
  5. Начиная со следующего релиза, кластеры Red Hat OpenShift откажутся от App Registry в пользу каталогов операторов (Operator Catalogs), базирующихся на образах контейнеров, доступных на quay.io.
  6. Долгосрочной заменой App Registry может стать поддержка спецификаций артефактов Open Container Initiative (OCI). В настоящее время она реализуется в виде родного функционала Quay и будет доступна для пользователей, когда саму спецификацию окончательно согласуют.

Все вышеперечисленное является частью продолжающихся инвестиций Red Hat в quay.io по мере того, как мы переходим от небольшой команды в духе стартапа к зрелой платформе, управляемой SRE. Мы знаем, что многие наши клиенты полагаются на quay.io в своей повседневной работе (включая Red Hat!) и стараемся быть максимально открытыми в отношении недавних сбоев и продолжающихся усилий стать лучше.

P.S. от переводчика


Читайте также в нашем блоге:

Подробнее..

Практические истории из наших SRE-будней. Часть 3

25.12.2020 10:05:30 | Автор: admin
Рады продолжить цикл статей с подборками из недавних вызовов, случившихся в нашей повседневной практике эксплуатации. Для этого мы описываем свои мысли и действия, которые привели к их успешному преодолению.



Новый выпуск посвящён опыту с неожиданно затянувшейся миграцией одного Linux-сервера, знакомству с Kubernetes-оператором для ClickHouse, способу ускорить восстановление данных в сломавшейся реплике PostgreSQL и последствиями обновления CockroachDB. Если вы тоже думаете, что это может быть полезно или хотя бы просто интересно, добро пожаловать под кат!

История 1. Затянувшийся перенос сервера в виртуальную машину


План миграции


Казалось, что может пойти не так, если требуется перенести legacy-приложение с железного сервера в виртуальную машину? У приложения и его инфраструктуры привычный, хорошо понятный стек: Linux, PHP, Apache, Gearman, MySQL. Причины для миграции тоже обычны: клиент захотел уменьшить плату за хостинг, отказавшись от реального сервера, на котором остался только вспомогательный сервис (парсер соцсетей).

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

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

Общий план выглядит следующим образом:

  1. Произвести очистку сервера, поняв, сколько ресурсов требуется.
  2. Подготовить виртуальный сервер, выделить память, ядра, зарезервировать IP-адреса.
  3. Если требуется минимальный простой организовать внешний балансировщик, который можно переключить на свежесозданный виртуальный сервер, или же запустить копию приложения.
  4. Произвести начальную загрузку с образа выбранной ОС/дистрибутива, содержащего все необходимые драйверы, чтобы скопировать данные в виртуальную машину тем или иным способом.
  5. Создать chroot, чтобы исправить загрузчик системы.
  6. Переключить пользовательские запросы или сервисные задачи на новую систему.

Что ж, воспользуемся таким планом в очередной раз, попутно выясняя, какие нестандартные ситуации, оказывается, могут возникать.

Подготовка к миграции


Перед началом непосредственного переезда мы решили почистить сервер. На нем было занято 300 Гб диска, однако среди них удалось найти давно потерявшие актуальность бэкапы, совсем старые логи, а также излишки в базе данных (см. ниже). В результате файловую систему удалось оптимизировать до 60 Гб.

Отдельно хочется рассказать про похудение MySQL. Дело в том, что MySQL изначально была версии 5.5 и настроена без innodb_file_per_table. Из-за этого, как многие могут догадаться, файл ibdata1 разросся до 40 Гб. В таких ситуациях нам всегда помогает pt-online-schema-change (входит в состав Percona Toolkit).

Достаточно проверить таблицы, которые находятся в shared innodb tablespace:

SELECT i.name FROM information_schema.INNODB_SYS_TABLES i WHERE i.space = 0;

после чего запустить упомянутую команду pt-online-schema-change, которая позволяет совершать различные действия над таблицами без простоя и поможет нам совершить OPTIMIZE без простоя для всех найденных таблиц:

pt-online-schema-change --alter "ENGINE=InnoDB" D=mydb,t=test --execute

Если файл ibdata1 не слишком велик, то его можно оставить. Чтобы полностью избавиться от мусора в файле ibdata1, потребуется сделать mysqldump со всех баз, оставив только базы mysql и performance_schema. Теперь можно остановить MySQL и удалить ibdata1.

После перезапуска MySQL создаст недостающие файлы системного namespace InnoDB. Загружаем данные в MySQL и готово.

Подготовка дисков и копирование


Казалось бы, теперь можно произвести перенос данных с помощью dd, однако в данном случае это не представлялось возможным. На сервере был созданный с md RAID 1, который не хотелось бы видеть на виртуальной машине, так как её разделы создаются в Volume Group, которая создана на RAID 10. Кроме того, разделы были очень большие, хотя занято было не более 15% места. Поэтому было принято решение переносить виртуальную машину, используя rsync. Такая операция нас не пугает: мы часто мигрировали серверы подобным образом, хотя это и несколько сложнее, чем перенос всех разделов с использованием dd.

Что потребуется сделать? Тут нет особой тайны, так как некоторые шаги полностью соответствуют действиям при копировании диска с dd:

  1. Создаем виртуальную машину нужного размера и загружаемся с systemrescuecd.
  2. Делаем разбивку диска, аналогичную серверу. Обычно нужен root-раздел и boot с этим поможет parted. Допустим, у нас есть диск /dev/vda:

    parted /dev/vdamklabel gptmkpart P1 ext3 1MiB 4MiB t 1 bios_grubmkpart P2 ext3 4MiB 1024MiBmkpart P3 ext3 1024MiB 100%t 3 lvm 
    
  3. Создадим на разделах файловые системы. Обычно мы используем ext3 для boot и ext4 для root.
  4. Монтируем разделы в /mnt, в который будем chroot'иться:

    mount /dev/vda2 /mntmkdir -p /mnt/bootmount /dev/vda1 /mnt/boot
    
  5. Подключим сеть. Актуальные версии systemrescuecd построены на ArchLinux и предполагают настройку системы через nmcli:

    nmcli con add con-name lan1 ifname em1 type ethernet ip4 192.168.100.100/24 gw4 192.168.100.1 ipv4.dns "8.8.8.8 8.8.4.4"nmcli con up lan1
    
  6. Копируем данные: rsync -avz --delete --progress --exclude "dev/*" --exclude "proc/*" --exclude "sys/*" rsync://old_ip/root/ /mnt/
  7. Затем монтируем dev, proc, sys:

    mount -t proc proc /mnt/procmount -t sysfs sys /mnt/sysmount --bind /dev /mnt/dev
    
  8. Зайдем в полученный chroot: chroot /mnt bash
  9. Поправим fstab, изменив адреса точек монтирование на актуальные.
  10. Теперь надо восстановить загрузчик:
    1. Восстановим загрузочный сектор: grub-install /dev/vda
    2. Обновим конфиг grub: update-grub
  11. Обновим initramfs: update-initramfs -k all -u
  12. Перезагрузим виртуалку и загрузим перенесенную систему.

Используя этот алгоритм, мы перенесли сотни виртуальных машин и серверов, однако в этот раз что-то пошло не так

Проблема и её решение


Система упорно помнила различные дисковые подразделы, которые были до переноса на сервере. Проблем разобраться с mdadm не было достаточно просто удалить файл /etc/mdadm/mdadm.conf и запустить update-initramfs.



Однако система все равно пыталась найти еще и /dev/mapped/vg0-swap. Оказалось, что initrd пытается подключить swap из-за конфига, который добавляет Debian installer. Удаляем лишний файл, собираем initramfs, перезагружаемся и снова попадаем в консоль busybox.

Поинтересуемся у системы, видит ли она наши диски. lsblk выдает пустоту, да и поиск файлов устройств в /dev/disk/by-uuid/ не даёт результатов. Выяснилось, что ядро Debian Jessie 3.16 скомпилировано без поддержки virtio-устройств (точнее, сама поддержка, конечно, доступна, но для этого нужно загрузить соответствующие модули).

К счастью, модули добавляются в initrd без проблем: нужные модули можно либо прописать в /etc/initramfs-tools/modules, либо изменить политику добавления модулей в /etc/initramfs-tools/initramfs.conf на MODULES=most.



Однако магии и в этот раз не произошло. Даже несмотря на наличие модулей система не видела диски:



Пришлось в настройках виртуальной машины переключить диски с шины Virtio на SCSI такое действие позволило загрузить виртуальную машину.

В загруженной системе отсутствовала сеть. Попытки подключить сетевые драйверы (модуль virtio_net) ни к чему не привели.



Дабы не усложнять задачу и не затягивать переключение, было решено переключить и сетевые адаптеры на эмуляцию реального железа сетевой карты Intel e1000e. Виртуальная машина была остановлена, драйвер изменён, однако при запуске мы получили ошибку: failed to find romfile "efi-e1000.rom".



Поиск дал интересный результат: ROM-файл был потерян в Debian некоторое время назад и возвращать его в пакет коллеги не собирались. Однако этот же файл фигурирует в пакете ipxe-qemu, откуда и был с успехом взят. Оказалось, достаточно распаковать этот пакет (ipxe-qemu) и скопировать /usr/lib/ipxe/qemu/efi-e1000.rom в /usr/share/qemu/efi-e1000e.rom. После этого виртуальная машина с эмулированным адаптером начала стартовать.

Вы думаете, это всё? Конечно же, нет, когда в деле замешан e1000e Данный драйвер известен тем, что может под нагрузкой начать перезапускать сетевой адаптер. Именно это и произошло, когда мы стали загружать базу данных для приложения. Пришлось прибегнуть к старому способу с отключение аппаратного offload:

ethtool -K eth0 gso off gro off tso off

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

История 2. Безопасность для Kubernetes-оператора ClickHouse


Не так давно мы начали использовать ClickHouse operator от Altinity. Данный оператор позволяет гибко разворачивать кластеры ClickHouse в Kubernetes:

  • с репликацией для повышенной надёжности;
  • с шардами для горизонтального масштабирования.

Однако мы столкнулись с неожиданной проблемой: невозможностью задать пароль для юзера default, который используется для работы remote_servers по умолчанию. Всё дело в том, что в шаблонах генерации конфигов кластера нет возможности определения пароля для remote_servers. По этой причине невозможна одновременная работа с distributed-таблицами она будет падать с ошибкой:

[2020-11-25 15:00:20] Code: 516, e.displayText() = DB::Exception: Received from chi-cluster-cluster-0-0:9000. DB::Exception: default: Authentication failed: password is incorrect or there is no user with such name.

К счастью, ClickHouse позволяет сделать whitelist с использованием rDNS, IP, host regexp Так можнодобавить в конфиг кластера следующее:

      users:        default/networks/host_regexp: (chi-cluster-[^.]+\d+-\d+|clickhouse\-cluster)\.clickhouse\.svc\.cluster\.local$

Тогда кластер сможет нормально функционировать. В репозитории оператора есть issue по этому поводу (мы не забыли добавить туда и свой workaround). Однако не похоже, что там будут какие-то движения в ближайшее время из-за того, что потребуется хранить пароли в конфигурации remote_servers.

История 3. Ускоренная перезаливка реплик PostgreSQL


К сожалению, ничто не вечно и любая техника стареет. А это приводит к различным сбоям. Один из таких сбоев произошел на реплике баз данных PostgreSQL: отказал один из дисков и массив перешёл в режим read only.

После замены диска и восстановления работы сервера встал вопрос: как же быстро ввести его в строй, учитывая, что база у проекта довольно объемна (более 2 терабайт)?

Дело осложнялось тем, что репликация была заведена без слотов репликации, а за время, пока сервер приводили в чувство, все необходимые WAL-сегменты были удалены. Архивацией WAL в проекте никто не озаботился и момент для её включения был упущен. К слову, сами слоты репликации представляют угрозу в версиях PostgreSQL ниже 13, т.к. могут занять всё место на диске (а неопытный инженер о них даже не вспомнит). С 13-й версии PgSQL размер слота уже можно ограничить директивой max_slot_wal_keep_size.

Итак, казалось бы, надо вооружаться pg_basebackup и переливать базу с нуля, но по нашим подсчетам такая операция заняла бы 9 дней, и всё это время основной сервер БД работал бы без резерва. Что же делать? У нас же есть почти актуальные файлы, некоторые из которых база вообще не трогает, так как это старые партиции партицированных таблиц Но pg_basebackup требует чистой директории для начала копирования. Вот бы изобрести метод, который бы позволил докачать базу!..

И тут я вспомнил про исходный метод, которым мы снимали бэкапы еще во времена PostgreSQL 9.1. Он описывается в статье документации про Continuous Archiving and Point-in-Time Recovery. Суть его крайне проста и основана на том, что можно копировать файлы PgSQL, если вызвать команду pg_start_backup, а после процедуры копирования pg_stop_backup. В голове созрел следующий план:

  1. Создадим слот репликации для реплики командой на мастере:

    SELECT pg_create_physical_replication_slot('replica', true);
    

    Важно, чтобы при создании второй аргумент функции был именно true тогда база начнёт немедленно собирать сегменты WAL в этот слот, а не будет ждать первого подключения к нему.
  2. Выполним команду на мастере:

    SELECT pg_start_backup('copy', true);
    

    Снова важно, чтобы при создании второй аргумент функции был именно true тогда база немедленно выполнит checkpoint и можно будет начать копирование.
  3. Скопируем базу на реплику. Мы для этой цели использовали rsync:

    rsynс -avz --delete --progress rsync://leader_ip/root/var/lib/postgresql/10/main/ /var/lib/postgresql/10/main/
    

    С такими параметрами запуска rsync заменит изменившиеся файлы.
  4. По окончании копирования на мастере выполним:

    SELECT pg_stop_backup();
    
  5. На реплике положим такой recovery.conf с указанием нашего слота:

    standby_mode = 'on'primary_conninfo = 'user=rep host=master_ip port=5432 sslmode=prefer sslcompression=1 krbsrvname=postgres target_session_attrs=any'recovery_target_timeline = 'latest'primary_slot_name = replica
    
  6. Запустим реплику.
  7. Удалим слот репликации на реплике, так как он так же скопируется с мастера:

    SELECT pg_drop_replication_slot('replica');
    
  8. Проверим, что она появилась в системной таблице pg_stat_replication.

Однако один момент я всё-таки упустил. Мы выполнили копирование всех WAL-файлов, которые были на мастере. А значит даже тех, которые не требовались. Поэтому на следующий день после перелива реплики место на сервере с репликой начало заканчиваться. И пришлось думать над тем, как удалить бесхозные сегменты WAL.

Мы знаем, что checkpoint_timeout равен 1 часу. Следовательно, надо удалить все файлы старше 1 часа, но от какого момента? Для этого на мастере делаем запрос:

SELECT pg_walfile_name(replay_lsn) from pg_stat_replication;     pg_walfile_name      -------------------------- 0000000200022107000000C8(1 row)

Исходя из него сверяем временную метку файла:

stat /var/lib/postgresql/10/main/pg_wal/0000000200022107000000C8...Access: 2020-12-02 13:11:20.409309421 +0300Modify: 2020-12-02 13:11:20.409309421 +0300Change: 2020-12-02 13:11:20.409309421 +0300

у удаляем все файлы старше. С этим помогут find и bash:

# Вычислим смещениеdeleteBefore=`expr $(date --date='2020-12-02 13:11:20' +%s) - 3600`mins2keep=`expr $(expr $(expr $(date +%s) - $deleteBefore) / 60) + 1`# Удалим файлы размером 16 МБ (стандартный размер сегмента WAL),# которые старше, чем mins2keepfind /var/lib/postgresql/10/main/pg_wal/ -size 16M -type f -mmin +$mins2keep -delete

Вот и всё: реплика была перелита за 12 часов (вместо 9 дней), функционирует и очищена от мусора.

История 4. CockroachDB не тормозит?


После обновления CockroachDB до версии 20.2.x мы столкнулись с проблемами производительности. Они выражались в долгом старте приложения и общем снижении производительности некоторых типов запросов. На CockroachDB 20.1.8 подобного поведения не наблюдалось.

Изначально имелось предположение, что дело в сетевых проблемах в кластере Kubernetes. Однако подтвердить его не удалось: cеть чувствовала себя отлично.



В процессе дальнейшего изучения было обнаружено, что на производительность влияет наличие в кластере CockroachDB базы приложения Keycloak. Решили включить журналирование медленных логов кстати, в CockroachDB это делается командами:

SET CLUSTER SETTING sql.log.slow_query.latency_threshold = '100ms';SET CLUSTER SETTING sql.log.slow_query.internal_queries.enabled = 'true';

Благодаря этому стало ясно, что используемый в приложении драйвер PostgreSQL JDBC при старте делает запросы к pg_catalog, а наличие базы Keyсloak сильно влияет на скорость работы этих запросов. Мы пробовали загрузить несколько копий базы и с каждый загруженным экземпляром скорость работы pg_catalog падала всё ниже и ниже:

I201130 10:52:27.993894 5920071 sql/exec_log.go:225  [n3,client=10.111.7.3:38470,hostssl,user=db1] 3 112.396ms exec "PostgreSQL JDBC Driver" {} "SELECT typinput = 'array_in'::REGPROC AS is_array, typtype, typname FROM pg_catalog.pg_type LEFT JOIN (SELECT ns.oid AS nspoid, ns.nspname, r.r FROM pg_namespace AS ns JOIN (SELECT s.r, (current_schemas(false))[s.r] AS nspname FROM ROWS FROM (generate_series(1, array_upper(current_schemas(false), 1))) AS s (r)) AS r USING (nspname)) AS sp ON sp.nspoid = typnamespace WHERE typname = $1 ORDER BY sp.r, pg_type.oid DESC" {$1:"'jsonb'"} 1 "" 0 { LATENCY_THRESHOLD }

Вот тот же запрос, но с загруженной проблемной базой:

I201130 10:36:00.786376 5085793 sql/exec_log.go:225  [n2,client=192.168.114.18:21850,hostssl,user=db1] 67 520.064ms exec "PostgreSQL JDBC Driver" {} "SELECT typinput = 'array_in'::REGPROC AS is_array, typtype, typname FROM pg_catalog.pg_type LEFT JOIN (SELECT ns.oid AS nspoid, ns.nspname, r.r FROM pg_namespace AS ns JOIN (SELECT s.r, (current_schemas(false))[s.r] AS nspname FROM ROWS FROM (generate_series(1, array_upper(current_schemas(false), 1))) AS s (r)) AS r USING (nspname)) AS sp ON sp.nspoid = typnamespace WHERE typname = $1 ORDER BY sp.r, pg_type.oid DESC" {$1:"'jsonb'"} 1 "" 0 { LATENCY_THRESHOLD }

Получается, что тормозили системные таблицы CockroachDB.

После того, как клиент подтвердил проблемы с производительностью уже в облачной инсталляции CockroachDB, источник проблемы стал проясняться: было похоже на улучшенную поддержку SQL, что появилась в релизе 20.2. План запросов к схеме pg_catalog заметно отличался от 20.1.8, и мы стали свидетелями регрессии.

Собрав все факты, сделали issue на GitHub, где разработчики после нескольких попыток воспроизведения проблемы смогли подтвердить её и пообещали решить в скором времени. Исходя из этого клиент принял решение переходить на новую версию, так как сейчас баг мешает нам только при старте, увеличивая время старта инстанса приложения.

ОБНОВЛЕНО (уже после написания статьи): Проблемы были исправлены в релизе CockroachDB 20.2.3 в Pull Request 57574.

Заключение


Как видно, иногда даже очевидные и простые операции могут повлечь за собой головную боль. Но выход всё равно можно найти, не так ли?.. Надеюсь, эти истории помогут и другим инженерам в повседневной работе. Stay tuned!

P.S.


Читайте также в нашем блоге:

Подробнее..

Troubleshooting в Oracle

08.05.2021 18:17:24 | Автор: admin

Этот пост навеян статьями Часть 1. Логирование событий в Oracle PL/SQL и Часть 2. Идентификация событий происходящих в Oracle PL/SQL. В первую очередь, как специалисту по performance tuning и troubleshooting, хотелось бы прокомментировать некоторые нюансы.

1. Уровни детализации логгирования

В показанной системе не хватает гибкости настройки логгирования: как уровня детализации, так и места, куда их выводить. Можно было позаимствовать функциональность из широко известных систем логгирования а-ля java.util.logging (SLF4j, log4j и его вариации для других языков/систем, и тд), гибкую настройку для какого кода с какого уровня сообщений и куда их сохранять. Например, в том же log4plsql можно настроить вывод и в alert.log, и в trace file (с помощью `dbms_system.ksdwrt()`)

2. Пользовательские ошибки и сообщения

Из самой внутренней системы ошибок Оракл можно было позаимствовать использование UTL_LMS.FORMAT_MESSAGE. Кстати, сами ошибки(и events) можно посмотреть с помощью sys.standard.sqlerrm(N):

SQL> select sys.standard.sqlerrm(-1476) errmsg from dual;ERRMSG-------------------------------------ORA-01476: divisor is equal to zero

Примеры: err_by_code.sql, trace_events.sql

Кроме того, я, конечно, понимаю, что не все ошибки можно предусмотреть, но все-таки считаю, что их надо добавлять в exception handler после того как они уже были отловлены. Это будет полезно как минимум при последующих изменениях логики и будет проще видеть нестандартные или непредусмотренные ранее ситуации.

3. Что же делать в случае незалоггированных ошибок

Естественно, может случиться так, что существующая система логгирования не регистрирует какие-то неординарные ошибки, или даже ее совсем нет в базе. Тут могут быть полезны триггеры `after servererror on database/schema`. Простой минимальный пример: https://github.com/xtender/xt_scripts/blob/master/error_logging/on_database.sql

К сожалению, для полноценного и срочного решения неординарных проблем, ни системы логгирования, ни таких триггеров, может быть недостаточно, и тут на помощь приходит вся мощь самой встроенной системы событий Oracle.

Например, недавно Nenad Noveljic расследовал проблему c "TNS-12599: TNS:cryptographic checksum mismatch" для чего ему нужно было получить callstack:

К счастью, помимо использованного у него в статье "ERRORSTACK", есть еще большой список "ACTIONS", включающий в себя и "CALLSTACK":

В этой команде 12599 - это номер события(event), callstack - инструктирует сделать дамп call стека, level 2 - указывает вывести еще и аргументы функций, lifetime 1 - только один раз.

Более подробно об этом у Tanel Poder с примерами:
- http://tech.e2sn.com/oracle/troubleshooting/oradebug-doc
- https://tanelpoder.com/2010/06/23/the-full-power-of-oracles-diagnostic-events-part-2-oradebug-doc-and-11g-improvements/

Мало того, как сам Танел и посоветовал, можно еще воспользоваться и "trace()" для форматированного вывода shortstack():

Так что этим же мы можем воспользоваться этим для вывода callstack:

alter system set events '12599 trace("stack is: %\n", shortstack())';

Или в более новом формате:

alter system set events 'kg_event[12599]{occurence: start_after 1, end_after 1} trace("stack is: %\n", shortstack())';

Как вы видите, здесь я еще добавил фильтр на количество срабатываний: после первого выполнения и только 1 раз.

Покажу на примере "ORA-01476: divisor is equal to zero":

alter system set events 'kg_event[1476]{occurence: start_after 1, end_after 1} trace("stack is: %\n", shortstack())';

Здесь kg_event - это Kernel Generic event, 1476 - ORA-1476. После этого запускаем в своей сессии:

SQL> alter session set events 'kg_event[1476]{occurence: start_after 1, end_after 1} trace("stack is: %\n", shortstack())';Session altered.SQL> select 1/0 x from dual;select 1/0 x from dual        *ERROR at line 1:ORA-01476: divisor is equal to zeroSQL> select 1/0 x from dual;select 1/0 x from dual        *ERROR at line 1:ORA-01476: divisor is equal to zeroSQL> select 1/0 x from dual;select 1/0 x from dual        *ERROR at line 1:ORA-01476: divisor is equal to zero

И в трейсфайле получаем:

# cat ORA19_ora_12981.trcTrace file /opt/oracle/diag/rdbms/ora19/ORA19/trace/ORA19_ora_12981.trcOracle Database 19c Enterprise Edition Release 19.0.0.0.0 - ProductionVersion 19.9.0.0.0Build label:    RDBMS_19.9.0.0.0DBRU_LINUX.X64_200930ORACLE_HOME:    /opt/oracle/product/19c/dbhome_1System name:    LinuxNode name:      b7c493c7f9b0Release:        3.10.0-1062.12.1.el7.x86_64Version:        #1 SMP Tue Feb 4 23:02:59 UTC 2020Machine:        x86_64Instance name: ORA19Redo thread mounted by this instance: 1Oracle process number: 66Unix process pid: 12981, image: oracle@b7c493c7f9b0*** 2021-05-08T14:12:27.000816+00:00 (PDB1(3))*** SESSION ID:(251.9249) 2021-05-08T14:12:27.000846+00:00*** CLIENT ID:() 2021-05-08T14:12:27.000851+00:00*** SERVICE NAME:(pdb1) 2021-05-08T14:12:27.000855+00:00*** MODULE NAME:(sqlplus.exe) 2021-05-08T14:12:27.000859+00:00*** ACTION NAME:() 2021-05-08T14:12:27.000862+00:00*** CLIENT DRIVER:(SQL*PLUS) 2021-05-08T14:12:27.000865+00:00*** CONTAINER ID:(3) 2021-05-08T14:12:27.000868+00:00stack is: dbgePostErrorKGE<-dbkePostKGE_kgsf<-kgeade<-kgeselv<-kgesecl0<-evadiv<-kpofcr<-qerfiFetch<-opifch2<-kpoal8<-opiodr<-ttcpip<-opitsk<-opiino<-opiodr<-opidrv<-sou2o<-opimai_real<-ssthrdmain<-main<-__libc_start_main

Или, например, недавно я посоветовал использовать alter system set events 'trace[sql_mon.*] [SQL: ...] disk=high,memory=high,get_time=highres'; для выяснения причин, почему конкретный запрос не мониторится/сохраняется real-time SQL монитором (RTSM - Real Time SQL Monitor).

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

Подробнее..
Категории: Sql , Oracle , Logging , Performance , Troubleshooting

Категории

Последние комментарии

  • Имя: Макс
    24.08.2022 | 11:28
    Я разраб в IT компании, работаю на арбитражную команду. Мы работаем с приламы и сайтами, при работе замечаются постоянные баны и лаги. Пацаны посоветовали сервис по анализу исходного кода,https://app Подробнее..
  • Имя: 9055410337
    20.08.2022 | 17:41
    поможем пишите в телеграм Подробнее..
  • Имя: sabbat
    17.08.2022 | 20:42
    Охренеть.. это просто шикарная статья, феноменально круто. Большое спасибо за разбор! Надеюсь как-нибудь с тобой связаться для обсуждений чего-либо) Подробнее..
  • Имя: Мария
    09.08.2022 | 14:44
    Добрый день. Если обладаете такой информацией, то подскажите, пожалуйста, где можно найти много-много материала по Yggdrasil и его уязвимостях для написания диплома? Благодарю. Подробнее..
© 2006-2024, personeltest.ru