пятница, 2 июля 2021 г.

[prog.experience] Маленькая история про улучшение навигации по логам в arataga

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

Если кто-то не в курсе, то arataga -- это прототип производительного прокси-сервера, который мы делали для одного клиента, пока этот самый клиент не потерял интерес к данной разработке.

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

Поскольку нагрузка создавалась не тестовыми программами, а реальными клиентами, трафик которых был пущен через arataga, то мы столкнулись с рядом особенностей в реализации SOCKS/HTTP-протоколов. И для разбирательства с тем, правильно ли arataga ведет себя в тех или иных ситуациях, потребовалось шерстить логи.

Грубо говоря, ищешь в логе ситуацию, помеченную как WARN или ERR, а затем смотришь, что предшествовало и/или следовало за этой ситуацией.

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

Изначально казалось, что каждая строка лога содержит достаточное количество информации для идентификации конкретного подключения. Вот, например:

[2021-04-16 08:43:02.756] [arataga] [error] socks-3001-192.168.1.178-io_thr_1-v1: connection (3001,38) => socks5: PDU with auth methods too long, methods: 1, bytes read: 22
[2021-04-16 08:43:02.756] [arataga] [debug] socks-3001-192.168.1.178-io_thr_1-v1: connection (3001,38) removed (protocol_error), connections: 0/200

Здесь в каждой строке есть две метки, которые позволяют идентифицировать точку входа и конкретное соединение в этой точке входа:

  • socks-3001-192.168.1.178-io_thr_1-v1 -- это имя агента, который обслуживает конкретную точку входа. Имя составное и сообщает максимум информации об этой точке входа и об агенте: socks -- говорит о точке входа по протоколу SOCKS, точка входа открыта на порту 3001 адреса 192.168.1.178, точка входа привязана к io_thread с порядковым номером 1. Ну и это первая версия данного агента (если агент пересоздается в результате изменения конфигурации, то номер его версии будет увеличиваться);
  • (3001,38) -- это идентификатор соединения внутри конкретной точки входа (38-ое соединение на порту 3001).

По идее, если искать подстроки "socks-3001-192.168.1.178-io_thr_1-v1" и "(3001,38)", то в логе будет найдено все, что касается данного конкретного подключения на данной конкретной точке входа.

Проблема, однако, в том, что искать по двум подстрокам не удобно. Гораздо удобнее искать всего одну подстроку. А именно "(3001,38)" вместо "socks-3001-192.168.1.178-io_thr_1-v1".

Это проблема проявилась практически сразу, еще когда мы сами занимались отладкой первых версий arataga на собственных тестовых стендах. Собственно, поэтому и появилась в логе отдельная связка из номера порта и номера соединения на этом порту (та самая подстрока вида "(3001,38)"). Это помогало нам в нашей автономной отладке, т.к. у нас не было повторений номеров портов на точках входа.

Но когда arataga поработала под реальной нагрузкой в условиях, когда есть сотни точек входа с одинаковым номером TCP-порта (на разных IP-адресах), то выяснилось, что подстроки вида "(3001,38)" уже не позволяют легко отыскивать все, что касается конкретного подключения. Слишком уж много оказывалось вхождений "(3001,38)", относящихся к совсем другим точкам входа.

Поэтому arataga была немного доработана дла того, чтобы от пары (порт, номер соединения) перейти к триплету (уникальный ID, порт, номер соединения), где "уникальный ID" был бы неким более коротким и удобным синонимом для "socks-3001-192.168.1.178-io_thr_1-v1".

В результате сейчас в arataga записи в логе имеют вид:

[2021-04-29 09:04:34.558] [arataga] [error] http-5500-192.168.1.161-io_thr_0-v1: connection (6498_2185,5500,6) => update request-target failure: unable to parse request-target, http_parser_parse_url result: 1

Где подстрока "(6498_2185,5500,6)" уже однозначно указывает на строчки лога, относящиеся к конкретному соединению на конкретной точке входа (уникальный ID вида "6498_2185" назначен агенту "http-5500-192.168.1.161-io_thr_0-v1" при его создании):

[2021-04-29 09:04:33.981] [arataga] [info] http-5500-192.168.1.161-io_thr_0-v1: created, acl_id_seed: 6498_2185


Пора переходить к итогу и к морали.

Итог простой -- после того, как в arataga каждое соединение начало идентифицироваться не парой из (порт, номер соединения), а триплетом (уникальный ID, порт, номер соединения), то отыскивать в логах информацию, относящуюся к конкретному подключению, стало гораздо проще.

Мораль номер раз. При начале реальной эксплуатации обязательно возникнет необходимость в каких-то незапланированных доработках, которые существенно повысят удобство использования софта (или же упростят разбирательство с проблемами в софте). Эти доработки нельзя предугадать. Но желательно сделать.

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


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

четверг, 1 июля 2021 г.

[life.cinema] Очередной кинообзор (2021/06)

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

Но, чтобы убить всякую интригу и не порождать напрасных ожиданий, скажу кратко: глянуть можно разве что "Кислород" и, если вам понравилась первая часть "Тихого места", то "Тихое место 2" (но лучше не ждать чего-то выдающегося). И все, сорян.

Фильмы

Кислород (Oxygène, 2021). Был приятно удивлен. Не ждал от продукции Netflix чего-нибудь толкового. Но у них получилось. Посмотрел с удовольствием.

Тихое место 2 (A Quiet Place Part II, 2021). Если вам понравился первый фильм, то можно посмотреть и второй. Ну а если первый восторга не вызывал, то и второй точно не вызовет. Как по мне, то вторая часть смотрится даже хуже, чем первая. Плюс у них серьезный косяк с приглашением на роль сына того же актера, что и в первой части (мальчик за 3 года сильно вырос и в продолжении это выглядит несуразно).

Бесконечность (Infinite, 2021). Красочно и местами даже динамично. Но блин, насколько же все тупо! Хотя, если этот фильм ориентирован на зрителей в возрасте 10 лет, то может и нормально для такой аудитории.

Дальний космос (Stowaway, 2021). Вот реально был неплохой заход на то, чтобы снять достойную космическую фантастику. Но, во-первых, получилось слишком нудно и затянуто. Во-вторых, почему-то в фильме не уделили никакого внимания тому, как "безбилетник" вообще попал на борт. В-третьих, почему-то сопереживать персонажам не хочется. Может быть потому, что в какие-то моменты они ведут себя как идиоты.

Первый клон (Seobok, 2021). По описанию и трейлеру ожидал, что будет бодрый фантастический боевик. Оказались фантастически нудные сопли. Смотреть можно разве что тем, кто интересуется корейским кино.

Ледяной драйв (The Ice Road, 2021). Халтура. Как по задумке, так и по исполнению.

Игры шпионов (The Courier, 2020). Не зашло. Смотреть было не интересно (особенно после прочтения вот такого взгляда на значимость предателя Олега Пеньковского). Такое ощущение, что основная цель съемок сего фильма была в том, чтобы дать Камбербэтчу повторить подвиг Кристиана Бейла в "Машинисте". Ну а появление в фильме гостиницы под названием "Отель Василий" просто подвело жирную черту под всем этим безобразием.

Сериалы

За час до рассвета (2021). Треш, угар и голые сиськи. Впрочем, при нынешней глобальной толерастии "голые сиськи" -- это еще неплохо, могла бы быть и содомия в худшем смысле этого слова. Всерьез это творение обсуждать невозможно, настолько там все убого, уныло и оторвано от реальности, что главный и единственный вопрос -- где же авторы брали такую траву?

Призрак (2019). Редкая дрянь. Смело можно не смотреть.