Экспортёр метрик кластера 1С:Предприятия был готов. Это один файл на PowerShell: он спрашивает кластер штатной утилитой rac через сервер администрирования RAS и выкладывает числа по HTTP в том виде, в каком их забирает Prometheus. HTTP отдавал 200. Content-Type правильный, text/plain; version=0.0.4; charset=utf-8. Восемнадцать килобайт текста, 64 семейства метрик, 85 рядов. Семейство тут одна метрика по имени, а ряд её отдельное значение со своим набором меток, вроде имени информационной базы. Самопроверка печатала rac errors : 0. Файл для textfile-режима, из которого метрики забирает система мониторинга, писался без BOM и не оставлял за собой временных файлов. Восемь сборщиков отчитывались каждый своим onec_collector_success 1.
Потом я первый раз поднял рядом настоящий Prometheus. И увидел вот это:
health = down lastError = invalid metric type "gauge\r"
В базу не попал ни один ряд. Дашборд, который я к этому моменту уже нарисовал, был бы пустым целиком, все двадцать панелей. И так продолжалось бы ровно до того дня, когда кто-нибудь догадался бы посмотреть на то, что от экспортёра получают. Смотреть на сам экспортёр было бесполезно.
Виноват был перевод строки.
Сначала про то, зачем это вообще нужно
Справедливый вопрос: у нас есть журнал регистрации, технологический журнал, консоль кластера, у кого-то ЦКК. Зачем сюда ещё один зверь из мира админов.
Отвечу своей позицией. Список возможностей вы и без меня прочитаете. Всё, что перечислено выше, отвечает на вопрос "что было", и отвечает после того, как ты уже знаешь, где искать и в какой час. Консоль кластера показывает "прямо сейчас" и ничего не помнит. Технологический журнал помнит всё, но чтобы его прочитать, надо сначала решить, что именно спрашивать, и заплатить за это гигабайтами на диске.
Prometheus отвечает на другой вопрос: когда началось и что изменилось. Не "покажи мне ошибки", а "нарисуй память рабочих процессов за две недели". После этого разговор с руководителем перестаёт быть спором про ощущения.
И вторая причина, для меня более весомая. У админов инфраструктуры Grafana обычно уже стоит, и в ней уже есть диски, сеть, СУБД и виртуалки. 1С в этой картине единственное чёрное пятно: про неё идут спрашивать человека, потому что графика нет. Экспортёр (карточка Метрики кластера 1С в Prometheus и Grafana: экспортер и готовый дашборд) закрывает ровно это пятно, и стоит он ноль, потому что Prometheus и Grafana уже куплены и настроены не нами.
Если у вас этого стека нет и ставить его вы не собираетесь, дальше можно читать ради граблей. Они вообще не про Prometheus, они про то, как зелёные проверки врут.
Одна строка кода, из-за которой не работало ничего
Сборка текста метрик шла через StringBuilder, а строки склеивались методом AppendLine(). На Windows этот метод ставит в конец CRLF, то есть два символа: возврат каретки и перевод строки. Так устроено Environment.NewLine, и это правильное поведение для Windows.
Формат экспозиции Prometheus принимает только перевод строки. Возврат каретки в конце строки становится частью последнего токена. Строка # TYPE onec_sessions gauge превращается в объявление типа gauge\r, такого типа не существует, и парсер отказывается от всего документа.
Правка заняла одну строку: вместо AppendLine теперь Append со склейкой через явный "\n". После неё promtool check metrics на живом выводе проходит без замечаний, цель поднимается в up, а тот scrape занял 1,3 секунды.
Отдельно порадовал тестовый образец вывода, который лежал в репозитории для проверок. Он тоже был с CRLF и тоже не проходил promtool. То есть эталон, по которому сверялись, был испорчен той же болезнью, что и продукт. Пересобрал его из живого вывода после правки.
Почему все проверки были зелёными
Вот это интереснее самого бага. Проверок было много, и каждая делала ровно то, что обещала. Просто ни одна из них не смотрела на вывод глазами того, кто его будет читать.
Разберу по одной.
HTTP 200. Проверяет, что слушатель поднялся и отдал тело. Про содержимое тела код ответа не знает ничего. Двести приходит и на корректный документ, и на мусор.
Content-Type. Проверяет заголовок, который я сам же и выставил в коде. Это моё намерение, записанное в заголовок ответа. Фактом оно от этого не становится: я объявил, что отдаю формат экспозиции версии 0.0.4, и заголовок честно повторил объявление.
Длина 18 175 байт. Сравнивать её было не с чем: ожидаемой длины я заранее не считал, а записал ту, что получилась. Обрезанный документ такая проверка поймала бы, а лишний символ в конце каждой строки уже нет. С CRLF текст длиннее ровно на число строк, и эти двести с лишним байт выглядят в отчёте как честные данные.
64 семейства, 85 рядов. Считает их самопроверка, и считает по готовому тексту, ровно по тому, что уходит по HTTP. Толку ноль: на строки она режет его регулярным выражением, которому всё равно, стоит перед переводом строки возврат каретки или нет. Проверил уже после починки, на живом образце: один и тот же текст с CRLF и без даёт одинаковые числа. Свой вывод я разобрал своим же разбором, а он прощает ровно то, о чём автор не подумал.
Самопроверка с нулём ошибок. Ноль ошибок означал, что rac отработал и все восемь сборщиков вернули данные. Проверялся вход. Выхода эта проверка не касалась вовсе.
Отсутствие BOM в textfile. Единственная проверка, которая смотрела на сырые байты результата. Она искала конкретную известную мне проблему в начале файла и находила её отсутствие. CRLF в конце каждой строки она не искала, потому что я о нём не думал.
Складывается неприятная картина. Шесть проверок, и все шесть измеряли мои представления о продукте. До настоящего вывода добрались две, и обе смотрели на него моими глазами: одна искала известную мне беду в начале файла, вторая делила строки моим же разбором. Ни одна не задала вопрос, ради которого продукт написан: сможет ли Prometheus это разобрать.
Формулировка, которую я после этого записал себе в правила: открытый порт живость не доказывает. И шире: проверка, которую писал автор кода, по умолчанию проверяет то, что автор уже знает. Дефект живёт ровно в том месте, о котором автор не подумал. Раз не подумал, туда и проверка не поставлена.
Второй дефект того же класса: версия, которая не та
Экспортёр умеет поднять RAS сам, если тот не запущен. Первая версия этой функции искала ras.exe и брала самый свежий из установленных.
На стенде стояли две платформы. Самый свежий ras.exe оказался 8.3.27.2325, а агент кластера работал под 8.3.27.1606. RAS запустился, порт открылся, процесс живой. И отказался соединяться с агентом:
Различаются версии клиента и сервера (8.3.27.2325 - 8.3.27.1606)
Снова та же схема. Процесс есть, порт слушает, ошибок при запуске нет. Работы нет.
Правило, которое из этого выросло и которого я раньше нигде не встречал сформулированным: rac может быть новее RAS, а ras новее агента быть не может. Обе половины стенд показал по отдельности: rac версии 8.3.27.2325 с RAS версии 8.3.27.1606 работает без замечаний, а RAS версии 8.3.27.2325 с агентом 8.3.27.1606 не соединяется вовсе.
Теперь автозапуск берёт версию по работающему ragent: сначала из описания службы Windows, при неудаче из пути запущенного процесса. После этой правки прогон с нуля, без единого поднятого RAS, дал 64 семейства и ноль ошибок.
Третий: метрика, которой нет, и тревога, которая на неё смотрит
Этот нашёлся на приёмке, и он тоньше двух предыдущих.
Три семейства метрик по лицензиям (onec_licenses_issued, onec_license_available_users, onec_license_max_users) печатались только тогда, когда лицензии кому-то выданы. Логично: нет сеансов, нет выданных лицензий, печатать нечего.
Беда в том, что на эти метрики ссылаются панель дашборда и правило тревоги про заканчивающиеся лицензии. А покупатель первым делом запускает инструмент на тестовом кластере 1С, где сеансов нет. То есть ровно в тот момент, ради которого мы кладём в комплект готовый дашборд, человек видит пустую панель.
Напрашивалось решение "печатать нули". Оно неправильное, и вот почему.
У метрики onec_licenses_issued метки приходят из самой лицензии: тип, серия, сетевая или нет, кем выдана. Ряда без этих меток не существует. Напечатать ноль означает выдумать ряд с пустыми метками, который потом столкнётся в базе с настоящим и даст в графике ступеньку из ниоткуда.
Хуже с доступными пользователями. Ноль в onec_license_available_users немедленно зажигает правило "меньше десяти", и каждый пустой стенд начинал бы жизнь с ложной тревоги в первые пять минут. Ложная тревога в мониторинге дороже отсутствующей метрики: на алерты, которые врут с первого дня, быстро перестают смотреть вообще.
Поэтому решение вышло третье: девятый сборщик, который спрашивает лицензию не у сеансов, а у рабочего процесса, командой rac process list --licenses. На пустом стенде он нашёл настоящий ключ, которым держится сам rphost. Ряд появляется потому, что лицензия там действительно есть, а не потому, что мы напечатали ноль.
Числа в начале статьи сняты до этой правки. В образце, который уезжает покупателю, семейств по-прежнему 64, а рядов уже 95.
Теперь про сам RAS, из-за которого всё это стоит на месте
Всё описанное собирает данные через rac, а тот разговаривает с кластером через RAS. В проде RAS живёт службой Windows, и с этой службой есть одна особенность, которая стоит отдельного абзаца.
Служба ставится примерно так:
sc create "1C:Enterprise 8.3 Remote Server" binPath= "C:\Program Files\1cv8\8.3.20.1914\bin\ras.exe cluster --service --port=1545 localhost:1540" start= auto obj= .\имя_локальной_учётки password= пароль_этой_учётки
Три вещи, которые здесь важны и которые в документации не выделены.
Порт 1545 и порт 1540 это разные вещи, и они стоят в строке рядом. 1545 это порт, на котором слушает сам RAS. 1540 это порт агента кластера, к которому RAS подключается. Перепутать их легко, а диагностика при этом невнятная: служба стартует и молчит.
Учётка отдельная, локальная, не LocalSystem. Это правильно с точки зрения прав, и это же означает, что пароль лежит в скрипте установки открытым текстом. Типовая практика и типовая же дыра: скрипт потом годами живёт в папке администратора.
Путь к ras.exe содержит версию платформы. Вот это и есть главная грабля эксплуатации. Обновили платформу, старый каталог убрали, служба указывает в пустоту. Она не перестаёт существовать, она просто перестаёт стартовать, и мониторинг умирает молча в тот момент, когда вы заняты обновлением и точно не смотрите на графики.
Поэтому нормальный скрипт установки начинается со sc stop и sc delete, и только потом идёт sc create. Он рассчитан на то, что его запустят повторно после каждого обновления платформы. Если у вас RAS ставился один раз руками и с тех пор не трогался, проверьте прямо сейчас, на какую версию смотрит binPath.
Ровно та же логика, что с автозапуском из предыдущего раздела: версия платформы зашита в путь, а путь живёт дольше платформы.
Что ещё оказалось не так, как в документации
Раз уж речь про то, что проверять надо реальность, а не ожидания, вот четыре мелочи из разбора вывода rac. Каждую я обнаружил на живом кластере, и ни одной не ждал.
Кодировка. При перенаправлении вывода rac пишет в UTF-8, и кириллица в имени кластера доезжает целой. Это приятно и это же ловушка: под другой локалью вывод может приехать в OEM-кодировке, и тогда имя кластера превратится в мусор ровно в метке метрики, то есть навсегда испортит ряд в базе. У меня на этот случай стоит отдельная ветка с жёстким декодером, который падает на невалидном UTF-8 и переключается на OEM. На моём стенде она не срабатывает ни разу, и это тот редкий случай, когда ни разу не сработавший код оставлен намеренно.
Значения с двоеточиями. Вывод rac выглядит как пары "ключ : значение", и разбирать его хочется поиском первого двоеточия. Так делать нельзя: у сеанса веб-клиента поле с адресом содержит IPv6 вида fe80::..., и разбор по первому двоеточию режет адрес пополам. Ключ приходится ловить по началу строки.
Значения в кавычках. Имя кластера приезжает как name : "Локальный кластер", вместе с кавычками. Если их не снять, кавычки уедут внутрь метки метрики и удвоятся при экранировании.
Служебные соединения без базы. Соединения планировщика заданий и служебных вызовов агента приходят с нулевым идентификатором информационной базы. Разрешение идентификатора в имя для них не работает по определению, и без отдельной обработки они получили бы пустую метку. У меня они помечены явным infobase="cluster-service": пустая метка в Prometheus это тоже значение, и потом её приходится вычищать из каждого запроса.
Имена баз, кстати, тоже отдельная работа. В сеансах и соединениях база приходит идентификатором, а человеку нужно имя, поэтому карта идентификаторов в имена строится отдельным вызовом и подставляется при сборе. Иначе дашборд показывает шестнадцатеричные строки, и пользоваться им невозможно.
Что я поменял в способе проверять
Вывод из трёх дефектов один и тот же, поэтому и лечение одно.
Проверять надо тем инструментом, который будет читать результат. Своими проверками вы измеряете себя. Для формата экспозиции это promtool check metrics: он разбирает документ ровно так же, как сервер, и ловит и CRLF, и дубли HELP, и неправильный тип. Одна команда, которой не было в проекте, отменяет шесть моих собственных зелёных проверок.
Для правил тревог это promtool check rules, для конфигурации promtool check config. Восемь наших правил после этого прошли проверку и были загружены живым сервером, у всех восьми health=ok. Одно правило пришлось поправить после живого срабатывания: чтение глазами его пропустило.
И один настоящий прогон стоит десяти проверок вокруг. Дашборд, который до стенда существовал как валидный JSON с двадцатью панелями, на стенде дал 20 панелей с данными из 20 на кластере с одним сеансом и 14 из 20 на кластере без сеансов. Шесть пустых это честная пустота: пока никто не работает, рисовать в панели "самый долгий вызов прямо сейчас" нечего.
Импорт при этом делался тем же вызовом, которым пользуется сам интерфейс. То есть проверен именно тот путь, который обещан покупателю: загрузил файл, выбрал источник данных, увидел кластер.
Что осталось непроверенным
Раз уж статья про то, что зелёные проверки врут, честно назову границы собственных.
Стенд был одним рабочим сервером с одним rphost и четырьмя базами. Кластер из нескольких рабочих серверов проверен только логикой кода. Сбор занимает от 1,3 до 2,4 секунды на одном сеансе, это пять замеров подряд, а как оно масштабируется на сотнях сеансов, я не мерил. Интервал опроса в поставке стоит 30 секунд, и стоит он с запасом на глаз: замера под ним нет. Администратора кластера на стенде нет, поэтому ключи с логином и паролем проброшены в rac, но живьём не проверены ни разу. Linux в автопоиске путей учтён и ни разу не запускался.
Единицы измерения я сверял с операционной системой, документация тут помогает мало: memory-size рабочего процесса у rac оказался 1 700 868, и ровно столько же килобайт показал PrivateMemorySize64 того же процесса в тот же момент. Числа буквально одинаковые, разная только подпись. Держится вывод при этом не на точности совпадения: байты от килобайт отличаются в 1024 раза, такую разницу видно при любой погрешности. Значит килобайты, значит умножаем на 1024 и отдаём в байтах, как требует соглашение об именовании метрик. На приёмке замер повторили независимо и уже на другом прогоне: 1 739 395 072 байта против 1 736 196 096 у процесса, разошлось на 0,18 процента за секунды между двумя чтениями.
Короче
Если вы делаете что-то, что отдаёт данные наружу, найдите инструмент, который эти данные читает на стороне потребителя, и прогоните им свой вывод до того, как объявите готовность. Свои проверки написаны из вашей картины мира, а дефект сидит в том месте, где эта картина неполная.
Мой экспортёр отдавал HTTP 200 и не работал вообще. Все мои проверки были зелёные, потому что все их писал я. Красным он стал от инструмента, который про мои намерения ничего не знал.
Экспортер из этой статьи: Метрики кластера 1С в Prometheus и Grafana: экспортер и готовый дашборд
Другие наши инструменты:
- Анализ нагрузки кластера 1С - тот же кластер, но без внешнего стека: кто держал базу и кто грузил сервер, прямо из 1С. Если Prometheus у вас нет и не будет, начинать стоит отсюда.
- Чек-ап сервера 1С - настройки кластера и рабочих процессов. Графики показывают, что память растёт, а этот отвечает, какая галочка это разрешила.
- Чек-ап СУБД под 1С - вторая половина картины. Кластер бывает настроен верно, а тормозит всё равно, и тогда вопросы к базе данных.
- Журнал транзакций переполнен: кто держит и что делать - самая частая ночная авария из тех, где память растёт ровно и предсказуемо, а логи об этом молчат.
Вступайте в нашу телеграмм-группу Инфостарт