Server Admin Авторский блог системного администратора
Приветствую вас джентльмены!
Хочу с помощью ELK собирать логи с почтового сервера MDaemon. Сервер пишет лог в файл и как бы делит "записи" на блоки внутри файла и как я понимаю, разделает эти блоки пунктиров в виде ----------. Получается примерно так, если нужно сделать блок с записью о там, что пользователь подключился и отправил письмо, MDaemon делает это бок из строчек. В итоге один блок может состоять от 1 до 20+ строчек. И проблема в том, что в ELK прилетают все эти строчки как отдельный логи. К примеру, если блок состоит из 10 строчек, то в кибане это выглядит как будто пришло 10 логов, соответственно ничего нельзя понят что к чем. Я так понимаю нужно создать какой-то фильт в logstash, но под каждую строчку писать фильтр это жесть, а если учесть что блок может состоять от 1 и больше строчки, то это вообще вилы.
Все примеры из интернетов показаны на логах в которых запись состоит из одной строчки, то же nginx, apache etc.
Надеюсь объяснил понятно суть проблемы. Скину кусок лога и скин вывода в кибане.
Кусок лога с MDaemon:
START Event Log / MDaemon PRO v13.0.4, SMTP (in) log information
-------------------------------------------------------------------------------
Event Time/Date Event Description
-------------------------------------------------------------------------------
Thu 2018-12-13 00:00:19: Session 229484; child 1
Thu 2018-12-13 00:00:19: Accepting SMTP connection from [10.3.2.4:61004] to [10.0.0.21:25]
Thu 2018-12-13 00:00:23: --> 220 mail.adk.kz ESMTP MDaemon 13.0.4; Thu, 13 Dec 2018 00:00:23 +0600
Thu 2018-12-13 00:00:23: * Winsock Error 10053
Thu 2018-12-13 00:00:23: SMTP session terminated (Bytes in/out: 0/71)
Thu 2018-12-13 00:00:23: ----------
Thu 2018-12-13 00:00:23: Session 229485; child 2
Thu 2018-12-13 00:00:23: Accepting SMTP connection from [10.3.2.4:61003] to [10.0.0.21:25]
Thu 2018-12-13 00:00:23: --> 220 mail.adk.kz ESMTP MDaemon 13.0.4; Thu, 13 Dec 2018 00:00:23 +0600
Thu 2018-12-13 00:00:23: * Winsock Error 10053
Thu 2018-12-13 00:00:23: SMTP session terminated (Bytes in/out: 0/71)
Thu 2018-12-13 00:00:23: ----------
Thu 2018-12-13 00:00:38: Session 229493; child 3
Thu 2018-12-13 00:00:38: Accepting SMTP connection from [197.248.39.202:58444] to [10.0.0.21:25]
Thu 2018-12-13 00:00:38: --> 220 mail.adk.kz ESMTP MDaemon 13.0.4; Thu, 13 Dec 2018 00:00:38 +0600
Thu 2018-12-13 00:00:38: <-- HELO mail.adk.kz
Thu 2018-12-13 00:00:38: --> 250 mail.adk.kz Hello mail.adk.kz, pleased to meet you
Thu 2018-12-13 00:00:39: <-- AUTH LOGIN
Thu 2018-12-13 00:00:39: --> 334 VXNlcm5hbWU6
Thu 2018-12-13 00:00:39: <-- dmlyZ2ls
Thu 2018-12-13 00:00:39: --> 334 UGFzc3dvcmQ6
Thu 2018-12-13 00:00:39: <-- ***
Thu 2018-12-13 00:00:39: --> 535 Authentication failed (login must use full email address)
Thu 2018-12-13 00:00:40: <-- QUIT
Thu 2018-12-13 00:00:40: --> 221 See ya in cyberspace
Thu 2018-12-13 00:00:40: SMTP session terminated (Bytes in/out: 56/252)
Thu 2018-12-13 00:00:40: ----------
Thu 2018-12-13 00:00:44: Session 229495; child 3
Thu 2018-12-13 00:00:44: Accepting SMTP connection from [10.1.0.110:50168] to [10.0.0.21:25]
Thu 2018-12-13 00:00:44: --> 220 mail.adk.kz ESMTP MDaemon 13.0.4; Thu, 13 Dec 2018 00:00:44 +0600
Thu 2018-12-13 00:00:44: <-- QUIT
Thu 2018-12-13 00:00:44: --> 221 See ya in cyberspace
Thu 2018-12-13 00:00:44: SMTP session terminated (Bytes in/out: 6/97)
Thu 2018-12-13 00:00:44: ----------
Thu 2018-12-13 00:01:44: Session 229512; child 4
Thu 2018-12-13 00:01:44: Accepting SMTP connection from [10.1.0.110:42462] to [10.0.0.21:25]
Thu 2018-12-13 00:01:44: --> 220 mail.adk.kz ESMTP MDaemon 13.0.4; Thu, 13 Dec 2018 00:01:44 +0600
Thu 2018-12-13 00:01:44: <-- QUIT
Thu 2018-12-13 00:01:44: --> 221 See ya in cyberspace
Thu 2018-12-13 00:01:44: SMTP session terminated (Bytes in/out: 6/97)
Thu 2018-12-13 00:01:44: ----------
Thu 2018-12-13 00:00:23: Session 229486; child 3
Thu 2018-12-13 00:00:23: Accepting SMTP connection from [10.3.2.4:61006] to [10.0.0.21:25]
Thu 2018-12-13 00:00:23: --> 220 mail.adk.kz ESMTP MDaemon 13.0.4; Thu, 13 Dec 2018 00:00:23 +0600
Thu 2018-12-13 00:00:23: <-- EHLO SRV0301
Thu 2018-12-13 00:00:23: --> 250-mail.adk.kz Hello SRV0301, pleased to meet you
Thu 2018-12-13 00:00:23: --> 250-ETRN
Thu 2018-12-13 00:00:23: --> 250-AUTH LOGIN CRAM-MD5 PLAIN
Thu 2018-12-13 00:00:23: --> 250-8BITMIME
Thu 2018-12-13 00:00:23: --> 250-STARTTLS
Thu 2018-12-13 00:00:23: --> 250 SIZE 32000000
Thu 2018-12-13 00:00:23: <-- AUTH login YWxlcnRzQGFkay5reg==
Thu 2018-12-13 00:00:23: --> 334 UGFzc3dvcmQ6
Thu 2018-12-13 00:00:23: <--
Thu 2018-12-13 00:00:23: --> 235 Authentication successful
Thu 2018-12-13 00:00:23: Authenticated as alerts@adk.kz
Thu 2018-12-13 00:00:23: <-- MAIL FROM:<alerts@adk.kz>
Thu 2018-12-13 00:00:23: --> 250 <alerts@adk.kz>, Sender ok
Thu 2018-12-13 00:00:23: <-- RCPT TO:<it7@adk.kz>
Thu 2018-12-13 00:00:23: --> 250 <it7@adk.kz>, Recipient ok
Thu 2018-12-13 00:00:23: <-- DATA
Thu 2018-12-13 00:00:23: Creating temp file (SMTP): d:\mdaemon\queues\temp\md50000018664.tmp
Thu 2018-12-13 00:00:23: --> 354 Enter mail, end with <CRLF>.<CRLF>
Thu 2018-12-13 00:00:23: Message size: 584 bytes
Thu 2018-12-13 00:00:23: Создание сообщения successful: d:\mdaemon\queues\inbound\md50002493426.msg
Thu 2018-12-13 00:00:23: --> 250 Ok, message saved <Message-ID: >
Thu 2018-12-13 00:01:59: <-- QUIT
Thu 2018-12-13 00:01:59: --> 221 See ya in cyberspace
Thu 2018-12-13 00:01:59: SMTP session successful (Bytes in/out: 709/428)
Thu 2018-12-13 00:01:59: ----------
Thu 2018-12-13 00:00:23: Session 229487; child 4
Thu 2018-12-13 00:00:23: Accepting SMTP connection from [10.3.2.4:61005] to [10.0.0.21:25]
Thu 2018-12-13 00:00:23: --> 220 mail.adk.kz ESMTP MDaemon 13.0.4; Thu, 13 Dec 2018 00:00:23 +0600
Thu 2018-12-13 00:00:23: <-- EHLO SRV0301
Thu 2018-12-13 00:00:23: --> 250-mail.adk.kz Hello SRV0301, pleased to meet you
Thu 2018-12-13 00:00:23: --> 250-ETRN
Thu 2018-12-13 00:00:23: --> 250-AUTH LOGIN CRAM-MD5 PLAIN
Thu 2018-12-13 00:00:23: --> 250-8BITMIME
Thu 2018-12-13 00:00:23: --> 250-STARTTLS
Thu 2018-12-13 00:00:23: --> 250 SIZE 32000000
Thu 2018-12-13 00:00:23: <-- AUTH login YWxlcnRzQGFkay5reg==
Thu 2018-12-13 00:00:23: --> 334 UGFzc3dvcmQ6
Thu 2018-12-13 00:00:23: <-- ***
Thu 2018-12-13 00:00:23: --> 235 Authentication successful
Thu 2018-12-13 00:00:23: Authenticated as alerts@adk.kz
Thu 2018-12-13 00:00:23: <-- MAIL FROM:<alerts@adk.kz>
Thu 2018-12-13 00:00:23: --> 250 <alerts@adk.kz>, Sender ok
Thu 2018-12-13 00:00:23: <-- RCPT TO:<it9@adk.kz>
Thu 2018-12-13 00:00:23: --> 250 <it9@adk.kz>, Recipient ok
Thu 2018-12-13 00:00:23: <-- DATA
Thu 2018-12-13 00:00:23: Creating temp file (SMTP): d:\mdaemon\queues\temp\md50000018665.tmp
Thu 2018-12-13 00:00:23: --> 354 Enter mail, end with <CRLF>.<CRLF>
Thu 2018-12-13 00:00:23: Message size: 584 bytes
Thu 2018-12-13 00:00:23: Создание сообщения successful: d:\mdaemon\queues\inbound\md50002493427.msg
Thu 2018-12-13 00:00:23: --> 250 Ok, message saved <Message-ID: >
Thu 2018-12-13 00:01:59: <-- QUIT
Thu 2018-12-13 00:01:59: --> 221 See ya in cyberspace
Thu 2018-12-13 00:01:59: SMTP session successful (Bytes in/out: 709/428)
Thu 2018-12-13 00:01:59: ----------
Thu 2018-12-13 00:01:39: Session 229508; child 3
Thu 2018-12-13 00:01:39: Accepting SMTP connection from [185.111.183.9:41096] to [10.0.0.21:25]
Thu 2018-12-13 00:01:39: --> 220 mail.adk.kz ESMTP MDaemon 13.0.4; Thu, 13 Dec 2018 00:01:39 +0600
Thu 2018-12-13 00:01:39: <-- EHLO srv9.linktrackenv.com
Thu 2018-12-13 00:01:39: --> 250-mail.adk.kz Hello srv9.linktrackenv.com, pleased to meet you
Thu 2018-12-13 00:01:39: --> 250-ETRN
Thu 2018-12-13 00:01:39: --> 250-AUTH LOGIN CRAM-MD5 PLAIN
Thu 2018-12-13 00:01:39: --> 250-8BITMIME
Thu 2018-12-13 00:01:39: --> 250-STARTTLS
Thu 2018-12-13 00:01:39: --> 250 SIZE 32000000
Thu 2018-12-13 00:01:39: <-- MAIL FROM:<1ae0fd394ecbb8fbbad24f4029d9d5d8@linktrackenv.com> SIZE=103716
Thu 2018-12-13 00:01:39: Performing PTR lookup (9.183.111.185.IN-ADDR.ARPA)
Thu 2018-12-13 00:01:39: * D=9.183.111.185.IN-ADDR.ARPA TTL=(3) PTR=[srv9.linktrackenv.com]
Thu 2018-12-13 00:01:39: * Gathering A records...
Thu 2018-12-13 00:01:39: * D=srv9.linktrackenv.com TTL=(2) A=[185.111.183.9]
Thu 2018-12-13 00:01:39: ---- End PTR results
Thu 2018-12-13 00:01:39: Performing IP lookup (srv9.linktrackenv.com)
Thu 2018-12-13 00:01:39: * D=srv9.linktrackenv.com TTL=(2) A=[185.111.183.9]
Thu 2018-12-13 00:01:39: ---- End IP lookup results
Thu 2018-12-13 00:01:39: Performing IP lookup (linktrackenv.com)
Thu 2018-12-13 00:01:40: * P=010 S=000 D=linktrackenv.com TTL=(1) MX=[mail.linktrackenv.com] {185.111.183.3}
Thu 2018-12-13 00:01:40: ---- End IP lookup results
Thu 2018-12-13 00:01:40: Performing SPF lookup (linktrackenv.com / 185.111.183.9)
Thu 2018-12-13 00:01:40: * Policy: v=spf1 ip4:185.111.183.0/24 ~all
Thu 2018-12-13 00:01:40: * Evaluating ip4:185.111.183.0/24: match
Thu 2018-12-13 00:01:40: * Result: pass
Thu 2018-12-13 00:01:40: ---- End SPF results
Thu 2018-12-13 00:01:40: --> 250 <1ae0fd394ecbb8fbbad24f4029d9d5d8@linktrackenv.com>, Sender ok
Thu 2018-12-13 00:01:40: <-- RCPT TO:<hr@a-store.kz>
Thu 2018-12-13 00:01:40: hr@a-store.kz is an alias for hr1@adk.kz
Thu 2018-12-13 00:01:40: Производится поиск DNS-BL (185.111.183.9 – соединение с IP)
Thu 2018-12-13 00:01:40: * zen.spamhaus.org - прошло
Thu 2018-12-13 00:01:41: * smtp.dnsbl.sorbs.net - прошло
Thu 2018-12-13 00:01:41: * bl.spamcop.net - прошло
Thu 2018-12-13 00:01:41: * cbl.abuseat.org - прошло
Thu 2018-12-13 00:01:41: * sbl-xbl.spamhaus.org - прошло
Thu 2018-12-13 00:01:59: * dnsbl.njabl.org - прошло
Thu 2018-12-13 00:01:59: * ex.dnsbl.org - прошло
Thu 2018-12-13 00:01:59: * blackholes.uceb.org - не удалось - 208.91.196.120
Thu 2018-12-13 00:01:59: * relays.ordb.org - не удалось - 72.52.4.119
Thu 2018-12-13 00:02:17: * list.dsbl.org - прошло
Thu 2018-12-13 00:02:17: ---- Конечные результаты DNS-BL
Thu 2018-12-13 00:02:17: --> 250 <hr@a-store.kz>, Recipient ok
Thu 2018-12-13 00:02:17: <-- DATA
Thu 2018-12-13 00:02:17: Creating temp file (SMTP): d:\mdaemon\queues\temp\md50000018666.tmp
Thu 2018-12-13 00:02:17: --> 354 Enter mail, end with <CRLF>.<CRLF>
Thu 2018-12-13 00:02:17: Message size: 103716 bytes
Thu 2018-12-13 00:02:17: Performing DKIM lookup
Thu 2018-12-13 00:02:17: * File: d:\mdaemon\queues\temp\md50000018666.tmp
Thu 2018-12-13 00:02:17: * Message-ID: 8468260bf8bf69366d88f7a9ca307ffd@swift.generated
Thu 2018-12-13 00:02:18: * Result: neutral
Thu 2018-12-13 00:02:18: ---- End DKIM results
Thu 2018-12-13 00:02:18: Performing DomainKeys lookup (Sender: noreply@yellowpagesc1oud.com)
Thu 2018-12-13 00:02:18: * File: d:\mdaemon\queues\temp\md50000018666.tmp
Thu 2018-12-13 00:02:18: * Message-ID: 8468260bf8bf69366d88f7a9ca307ffd@swift.generated
Thu 2018-12-13 00:02:18: * Querying for policy: yellowpagesc1oud.com
Thu 2018-12-13 00:02:18: * Querying: _domainkey.yellowpagesc1oud.com ...
Thu 2018-12-13 00:02:18: * DNS: * Сервер имен не содержит допустимых записей нужного типа для этого домена.
Thu 2018-12-13 00:02:18: * Result: neutral
Thu 2018-12-13 00:02:18: ---- End DomainKeys results
Thu 2018-12-13 00:02:18: Passing message through Spam Filter (Size: 103716)...
Thu 2018-12-13 00:02:19: * 10 BAYES_99 BODY: Bayes spam probability is 99 to 100%
Thu 2018-12-13 00:02:19: * [score: 1.0000]
Thu 2018-12-13 00:02:19: * 0.0 URIBL_BLOCKED ADMINISTRATOR NOTICE: The query to URIBL was blocked.
Thu 2018-12-13 00:02:19: * See http://wiki.apache.org/spamassassin/DnsBlocklists#dnsbl-block
Thu 2018-12-13 00:02:19: * for more information.
Thu 2018-12-13 00:02:19: * [URIs: linktrackenv.com]
Thu 2018-12-13 00:02:19: * 1.3 URIBL_ABUSE_SURBL Contains an URL listed in the ABUSE SURBL
Thu 2018-12-13 00:02:19: * blocklist
Thu 2018-12-13 00:02:19: * [URIs: linktrackenv.com]
Thu 2018-12-13 00:02:19: * 3.0 MDAEMON_DNSBL MDaemon: marked by MDaemon's DNSBL
Thu 2018-12-13 00:02:19: * -0.5 RP_MATCHES_RCVD Envelope sender domain matches handover relay domain
Thu 2018-12-13 00:02:19: * 1.2 MONEY_BACK BODY: Money back guarantee
Thu 2018-12-13 00:02:19: * 0.2 BAYES_999 BODY: Bayes spam probability is 99.9 to 100%
Thu 2018-12-13 00:02:19: * [score: 1.0000]
Thu 2018-12-13 00:02:19: * 0.0 HTML_MESSAGE BODY: HTML included in message
Thu 2018-12-13 00:02:19: ---- End SpamAssassin results
Thu 2018-12-13 00:02:19: Spam Filter score/req: 15.20/7.0
Thu 2018-12-13 00:02:19: Message refused because spam score is too high
Thu 2018-12-13 00:02:19: --> 554 Sorry, message looks like SPAM to me
Thu 2018-12-13 00:02:19: SMTP session terminated (Bytes in/out: 103854/410)
Thu 2018-12-13 00:02:19: ----------
Thu 2018-12-13 00:02:44: Session 229526; child 1
Thu 2018-12-13 00:02:44: Accepting SMTP connection from [10.1.0.110:36752] to [10.0.0.21:25]
Thu 2018-12-13 00:02:44: --> 220 mail.adk.kz ESMTP MDaemon 13.0.4; Thu, 13 Dec 2018 00:02:44 +0600
Thu 2018-12-13 00:02:44: <-- QUIT
Thu 2018-12-13 00:02:44: --> 221 See ya in cyberspace
Thu 2018-12-13 00:02:44: SMTP session terminated (Bytes in/out: 6/97)
Возможно я не так понял как все это работает и копаю не в ту сторону.
Я понял суть проблемы. Тоже думал об этом на примере какого-то сервиса, не помню уже точно какого. Как лучше обыграть данную ситуацию не придумал. Тут надо либо формат логов на выходе менять на самом сервисе, либо мириться с тем, что логи будут в elk разбиты на строки. На просмотр и поиск это особо не влияет, а вот если нужно парсить строки, добавлять метаданные и строить дашборд, то будут сложности.
Если найдете подходящее решение, прошу поделиться информацией. Но мне кажется, тут ничего не придумать, чтобы получилось красиво. Что можно поделать, если у сервиса такой формат логов? Объединить все в одну строку? Но такой лог тоже не будет читаться.
Тоже уже давно думаю об этом. Если сможете подружить MD со стеком ELK, то поделитесь рецептом :)
Кстати говоря, такая же проблема будет и при сборе логов с postfix и dovecot. Там тоже любое действие разбито на отдельные строки в логе. Прием - отправка почты это тоже несколько строк лога. Думаю, тут в зависимости от того, что хочется видеть на дашборде, надо парсить отдельные строки, например, с адресом отправителя или получателя.
Я в итоге просто отправил весь лог postfix как есть в elk. Как минимум, появился удобный поиск и выборка по датам. Да и просто смотреть лог удобнее. Если нужна статистика, придется отдельно парсить разные строки и писать для каждого grok правила в logstash. И это очень неудобно. Возможно есть более красивое решение, с разбором уже принятых логов. Но мне такое неизвестно.
Думаю написать небольшой скриптик который будет парсить лог и переводить в более удобный формат json.
