Привет, Хабр.
В одном из проектов, связанных с мониторингом, мы используем Clickhouse, Prometheus, VictoriaMetrics, Grafana, Alertmanager и Vector.dev. Кстати, что общего у всех этих компонентов? Они написаны не на Java – это было одним из требований проекта, но речь ниже пойдет не об этом, а о Vector.dev.
![](https://habrastorage.org/getpro/habr/upload_files/871/705/f05/871705f0559f07e0b7ce8cc5dc5edf3e.jpg)
Хорошая статья про Vector.dev есть на Хабре – но мы решили проверить свою карму, затащив Vector.dev в PoC. На текущий момент полет вполне нормальный: используем ограниченное количество source и sink’ов: File, Clickhouse, HTTP, JournalD и, конечно, сам Vector и его логи (немного погоняли kubernetes_logs, кстати, интересный доклад по теме логов Kubernetes был на недавней VK Kubernetes Conf’23).
Как оно там, внутри
На данный момент у нас двухуровневая иерархия векторов:
агентский Vector.dev, который собирает логи с FreeIPA и OpenNebula серверов, а также наших Prometheus экспортеров;
центральный Vector.dev, который агрегирует данные от агентских векторов.
В планах добавить третий уровень – прокси для различных локаций или контуров, но пока без этого.
Центральный Vector.dev запущен в Kubernetes и отправляет данные в кластер ClickHouse, агентские ставятся просто из deb-пакетов.
File source или работа с файлами
Ниже опишу некоторые конфигурации вектора с примерами обрабатываемых файлов – информация не сакральная, так как, почитав документацию, можно к таким же настройкам и прийти – но, надеюсь, с примерами лог-файлов будет для кого-то более наглядно.
Многострочные логи
У File source есть такая конфигурация как multiline. Из названия понятно, что объединяет несколько строчек логов в одну запись. Интересно то, что даже если на первый взгляд кажется, что в логах нет многострочных записей, то это может быть заблуждение.
Вот пример вывода части файла, ничего не указывает на многострочные логи:
root@ipatest:/var/log/ipa# tail -20 ipa-backup.log
Starting httpd Service
Starting ipa-custodia Service
Starting pki-tomcatd Service
Starting ipa-otpd Service
Starting ipa-dnskeysyncd Service
2023-07-04T06:22:07Z DEBUG stderr=ipa: INFO: The ipactl command was successful
2023-07-04T06:22:07Z DEBUG Starting external process
2023-07-04T06:22:07Z DEBUG args=['/bin/gzip', '/tmp/tmpmn9v4iqsipa/ipa/files.tar']
2023-07-04T06:22:07Z DEBUG Process finished, return code=0
2023-07-04T06:22:07Z DEBUG stdout=
2023-07-04T06:22:07Z DEBUG stderr=
2023-07-04T06:22:07Z DEBUG Starting external process
2023-07-04T06:22:07Z DEBUG args=['tar', '--xattrs', '--selinux', '-czf', '/var/lib/ipa/backup/ipa-full-2023-07-04-09-22-07/ipa-full.tar', '.']
2023-07-04T06:22:08Z DEBUG Process finished, return code=0
2023-07-04T06:22:08Z DEBUG stdout=
2023-07-04T06:22:08Z DEBUG stderr=
2023-07-04T06:22:08Z INFO Backed up to /var/lib/ipa/backup/ipa-full-2023-07-04-09-22-07
2023-07-04T06:22:08Z INFO The ipa-backup command was successful
![](https://habrastorage.org/getpro/habr/upload_files/2ef/91f/024/2ef91f024e4baf8110397bfa2e26a611.png)
Но если покопаться в файле, то замечаем, что запись лога является многострочной. Если это не обрабатывать отдельно, то каждая новая строчка такой многострочной записи будет новой записью в ClickHouse и никак не связана с предыдущей строкой лога.
2023-07-04T06:21:38Z DEBUG args=['tar', '--exclude=/var/lib/ipa/backup', '--xattrs', '--selinux', '-cf', '/tmp/tmpmn9v4iqsipa/ipa/files.tar', '/usr/share/ipa/html', '/etc/pki/pki-tomcat', '/etc/dogtag/', '/var/lib/pki', '/var/lib/ipa/sysrestore', '/var/lib/ipa-client/sysrestore', '/var/lib/ipa/dnssec', '/var/lib/sss/pubconf/krb5.include.d/', '/var/lib/certmonger', '/var/lib/ipa', '/run/dirsrv', '/run/lock/dirsrv', '/etc/dirsrv/slapd-DOMAIN-DCS-LAN', '/var/lib/dirsrv/slapd-DOMAIN-DCS-LAN', '/etc/bind/named.conf', '/etc/bind/ipa-ext.conf', '/etc/bind/ipa-options-ext.conf', '/etc/bind/named.keytab', '/etc/resolv.conf', '/etc/default/pki-tomcat', '/etc/default/krb5-kdc', '/etc/default/ipa-dnskeysyncd', '/etc/default/ipa-ods-exporter', '/etc/default/bind9', '/etc/ipa/nssdb/pwdfile.txt', '/usr/local/share/ca-certificates/ipa.p11-kit', '/etc/nsswitch.conf', '/etc/krb5.keytab', '/etc/sssd/sssd.conf', '/etc/ldap/ldap.conf', '/etc/security/limits.conf', '/var/lib/ipa/gssproxy/http.keytab', '/etc/ipa/kdcproxy/ipa-kdc-proxy.conf', '/etc/apache2/conf-enabled/ipa-pki-proxy.conf', '/etc/apache2/conf-available/ipa-rewrite.conf', '/etc/apache2/mods-available/ssl.conf', '/etc/apache2/sites-available/default-ssl.conf', '/var/lib/ipa/certs/httpd.crt', '/var/lib/ipa/private/httpd.key', '/etc/apache2/conf-enabled/ipa.conf', '/etc/ssh/sshd_config', '/etc/ssh/ssh_config', '/etc/krb5.conf', '/var/lib/ipa-client/pki/kdc-ca-bundle.pem', '/var/lib/ipa-client/pki/ca-bundle.pem', '/etc/ipa/ca.crt', '/etc/ipa/default.conf', '/etc/dirsrv/ds.keytab', '/etc/chrony/chrony.conf', '/root/ca-agent.p12', '/var/lib/ipa/ra-agent.pem', '/var/lib/ipa/ra-agent.key', '/root/cacert.p12', '/root/kracert.p12', '/etc/krb5kdc/kdc.conf', '/var/lib/ipa/certs/kdc.crt', '/var/lib/ipa/certs/kdc.key', '/var/lib/ipa/certs/cacert.pem', '/etc/systemd/system/multi-user.target.wants/ipa.service', '/etc/systemd/system/apache2.service.d/ipa.conf', '/etc/systemd/system/multi-user.target.wants/sssd.service', '/etc/systemd/system/multi-user.target.wants/certmonger.service', '/etc/systemd/system/pki-tomcatd.target.wants/pki-tomcatd@pki-tomcat.service', '/etc/opendnssec/conf.xml', '/etc/opendnssec/kasp.xml', '/etc/opendnssec/zonelist.xml', '/etc/ipa/dnssec/softhsm2.conf', '/etc/ipa/dnssec/softhsm_pin_so', '/etc/ipa/dnssec/ipa-dnskeysyncd.keytab', '/etc/ipa/custodia/server.keys', '/etc/ipa/custodia/custodia.conf', '/etc/gssproxy/10-ipa.conf', '/etc/hosts', '/etc/systemd/system/pki-tomcatd@pki-tomcat.service.d/ipa.conf', '/etc/ipa/nssdb/cert9.db', '/etc/ipa/nssdb/key4.db', '/etc/ipa/nssdb/pkcs11.txt', '/etc/tmpfiles.d/dirsrv-DOMAIN-DCS-LAN.conf', '/etc/systemd/system/dirsrv@DOMAIN-DCS-LAN.service.d/ipa-env.conf', '/var/lib/ipa/passwds/ipatest.domain.dcs.lan-443-RSA']
![](https://habrastorage.org/getpro/habr/upload_files/5e3/896/a86/5e3896a86737d9094f877d6e90fff57e.png)
Поэтому для обеспечения логической связности сообщения логов некоторые записи приходится обрабатывать как многострочные. Но с вектором это достаточно просто, мы использовали следующую конфигурацию на основе регулярных выражений (здесь нам помогает то, что каждая отдельно взятая запись начинается с временной метки):
[sources.logs_freeipa_backup]
type = "file"
include = [ "/var/log/ipa/*backup.log" ]
multiline.start_pattern = "^\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}Z"
multiline.condition_pattern = "^\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}Z"
multiline.mode = "halt_before"
multiline.timeout_ms = 1000
Вектор уже сам склеивает многострочные сообщения и отправляет их в ClickHouse объединенными.
Fingerprint
Другой пример – это настройка правила определения «уникальности» лог-файла. Параметр fingerprint определяет, как файл идентифицируется. Это актуально для систем с включенной ротацией логов.
По умолчанию – это checksum (берутся строчки с начала файла и по ним считается контрольная сумма, даже интереснее по умолчанию берется одна первая строка). С одной стороны, какие могут быть проблемы? Действительно, большинство логов содержат в каждой записи уникальное значение – временную метку. Тогда все просто. Оказывается, что есть системы и лог-файлы, у которых шапка в начале каждого лог-файла одинаковая. В итоге получаем, что вектор не может различить файлы.
К сожалению, настройки, позволяющие игнорировать какое-то количество строк при вычислении контрольной суммы в векторе, нет (т.е., по сути, игнорировать статический заголовок), есть настройка (fingerprint.ignored_header_bytes), позволяющая пропускать определенное количество байт, но по выводы ниже видно, что рассчитать в нашем случае количество байт не получится. Но есть другая настройка – она определяет, какое количество строк учитывается для подсчета контрольной суммы. Ей мы и воспользовались.
root@ipatest:/var/log/dirsrv/slapd-DOMAIN-DCS-LAN# head -10 access
389-Directory/1.4.3.6 B2022.332.1108
ipatest.domain.dcs.lan:636 (/etc/dirsrv/slapd-DOMAIN-DCS-LAN)
[03/Oct/2023:14:30:50.945787186 +0300] conn=45 op=24857 SRCH base="ou=sessions,ou=Security Domain,o=ipaca" scope=2 filter="(objectClass=securityDomainSessionEntry)" attrs="cn"
[03/Oct/2023:14:30:50.946824663 +0300] conn=45 op=24857 RESULT err=0 tag=101 nentries=0 etime=0.001495205
[03/Oct/2023:14:31:35.998247986 +0300] conn=1561621 fd=132 slot=132 connection from local to /var/run/slapd-DOMAIN-DCS-LAN.socket
[03/Oct/2023:14:31:35.999675738 +0300] conn=1561621 AUTOBIND dn="cn=Directory Manager"
[03/Oct/2023:14:31:35.999694789 +0300] conn=1561621 op=0 BIND dn="cn=Directory Manager" method=sasl version=3 mech=EXTERNAL
[03/Oct/2023:14:31:35.999839429 +0300] conn=1561621 op=0 RESULT err=0 tag=97 nentries=0 etime=0.001454494 dn="cn=Directory Manager"
[03/Oct/2023:14:31:36.096347939 +0300] conn=1561621 op=1 SRCH base="cn=computers,cn=accounts,dc=domain,dc=dcs,dc=lan" scope=2 filter="(memberOf=cn=adtrust agents,cn=sysaccounts,cn=etc,dc=domain,dc=dcs,dc=lan)" attrs="* aci"
![](https://habrastorage.org/getpro/habr/upload_files/8e2/29b/1ee/8e229b1ee22f806c536a62739d8493a6.png)
[sources.logs_freeipa_access]
type = "file"
include = [ "/var/log/dirsrv/*/access" ]
fingerprint.strategy = "checksum"
fingerprint.lines = 4
fingerprint.ignored_header_bytes = 0
Здесь установили, что «уникальность» файла логов отслеживается по первым 4 строкам (fingerprint.lines).
С чем столкнулись
Лимит на открытые файлы
Одна из задач была связана с мониторингом OpenNebula, включая логи виртуальных машин в ней. У OpenNebula может быть несколько нод, виртуальные машины между ними могут перемещаться и так далее. Машин в кластере может быть много, даже не единовременно, а вообще за всю историю существования кластера. Лог-файл обычно называется как <id_vm>.log. Для мониторинга мы указывали все файлы в каталоге с расширением log (/var/log/libvirt/qemu/*.log). Нам иногда не хватило файловых дескрипторов – мы получили ошибку “Too many open files (os error 24)”. Начали разбираться с выводов утилиты ulimit.
# ulimit -Sa
core file size (blocks, -c) 0
data seg size (kbytes, -d) unlimited
scheduling priority (-e) 0
file size (blocks, -f) unlimited
pending signals (-i) 4122747
max locked memory (kbytes, -l) 65536
max memory size (kbytes, -m) unlimited
open files (-n) 1024
pipe size (512 bytes, -p) 8
POSIX message queues (bytes, -q) 819200
real-time priority (-r) 0
stack size (kbytes, -s) 8192
cpu time (seconds, -t) unlimited
max user processes (-u) 4122747
virtual memory (kbytes, -v) unlimited
file locks (-x) unlimited
# ulimit -Ha
core file size (blocks, -c) unlimited
data seg size (kbytes, -d) unlimited
scheduling priority (-e) 0
file size (blocks, -f) unlimited
pending signals (-i) 4122747
max locked memory (kbytes, -l) 65536
max memory size (kbytes, -m) unlimited
open files (-n) 1048576
pipe size (512 bytes, -p) 8
POSIX message queues (bytes, -q) 819200
real-time priority (-r) 0
stack size (kbytes, -s) unlimited
cpu time (seconds, -t) unlimited
max user processes (-u) 4122747
virtual memory (kbytes, -v) unlimited
file locks (-x) unlimited
Нас интересовал параметр open files (-n) 1024. Проблему временно решили, указав сервису вектора увеличенные значения LimitNOFILE/LimitNOFILESoft:
[Unit]
Description=Vector
Documentation=https://vector.dev
After=network-online.target
Requires=network-online.target
[Service]
…
StandardOutput=file:/var/log/monitoring/vector.log
ExecStartPre=/usr/bin/vector validate
ExecStart=/usr/bin/vector
ExecReload=/usr/bin/vector validate
ExecReload=/bin/kill -HUP $MAINPID
Restart=always
AmbientCapabilities=CAP_NET_BIND_SERVICE
EnvironmentFile=-/etc/default/vector
LimitNOFILE=2048
LimitNOFILESoft=2048
Параметр ignore_older
Решая проблему выше (и не только ее), хотели добиться, чтобы Vector.dev прекращал отслеживать логи в файлах, которые не менялись какое-то время (например, 30 дней). На самом деле, конкретно с проблемой для логов виртуальных машин нам бы это не помогло, т.к. виртуальна машина может быть остановлена на какое-то время, а потом снова включена (если это демо стенд), тогда ее «новые» логи уже потерялись бы (хотя для продуктивных нагрузок параметр в 30 дней вполне бы мог и работать).
К сожалению, такой настройки не нашли. Нашли параметр ignore_older. Сначала показалось, что это то, что требуется, но нет, это про другое. Документацию разработчики Vector.dev поправили.
TOML vs YAML
Изначально мы писали конфиги Vector.dev в toml, но потом yaml был выбран командой Vector.dev как формат по умолчанию с версии 0.33.0. Мы решили не терять времени, и наш инженер оперативно переписал конфигурацию агрегирующего Vector.dev из toml в yaml. С конфигурацией клиентских векторов решили действовать постепенно. Предлагаемая командой Vector.dev утилита vector convert-config справляется вполне хорошо, поэтому для нас изменение формата не стала большой проблемой (хотя лично мне для описания правил преобразования toml нравился больше).
Алертинг с помощью Vector.dev (интеграция с Alertmanager)
Неожиданно мы нашли еще одно интересное применение для Vector.dev – пока только в целях исследования. Требовалось опробовать функциональность оповещения на основе встречающихся паттернов в логах, принимаемых вектором. На помощь нам пришел HTTP source. Паттерны выделяли с помощью регулярных выражений, далее таким образом отфильтрованные записи направляли в HTTP Source, который отправлял запрос к Alert Manager’у. Таким образом реализовали как создание алерта, так и его закрытие. Ниже приведен пример конфигурации, наши реальные обработки учитывают больше условий и в целом сложнее устроены.
event_syslog_error:
type: remap
inputs:
- filter_syslog_errors
source: |
. |= parse_regex!(string!(.message), r'systemd.+?: Failed to start (?P<iname>.+)\.$')
.alertname = "Service " + .iname + " failure"
.severity = "critical"
filter_recover_syslog_error:
type: filter
inputs:
- vector
condition:
type: vrl
source: |
match_any(string!(.message), [
r'systemd.+?: Started (?P<iname>.+)\.$'
])
recover_syslog_error:
type: remap
inputs:
- filter_recover_syslog_error
source: |
. |= parse_regex!(string!(.message), r'systemd.+?: Started (?P<iname>.+)\.$')
.alertname = "Service " + .iname + " failure"
.severity = "critical"
Полет нормальный
Пока считаем, что полет нормальный, и сегодня мы продолжаем использовать Vector.dev. Немного не хватает каких-то source\sink, наличия для самого Vector.dev дашборда в Grafana (это пережили), возможности написания расширений и пользовательских функций (все-таки VRL - это не Python, как минимум в функциональности).
Надеюсь, что статья для кого-то будет полезной, сообщество Vector.dev будет расти, а значит будет появляться новая функциональность, отправляться pull request’ы. Мы же в ближайшем времени планируем подключить Vector.dev к мониторингу логов Kubernetes кластеров.