16 апреля 2015 в 10:45

Централизованый сбор Windows event логов, без установки агента, с последующей визуазизацией средствами ELK

Задача по централизованой обработке логов достаточно просто формулируется и возникает, когда требуется отслеживать работу большого количества серверов. Думаю, не стоит упоминать о том, что из логов можно получать массу информации о жизнедеятельности и самочувствии систем. О том, что писать и читать логи столь же важно как и уметь писать программы.

Соответственно для реализации такой системы перед администратором ставятся задачи: во-первых, каким образом эти логи собирать, во-вторых, каким образом с ними удобно и централизованно работать. Благодаря достаточно развитой связке ELK (Elasticsearch + Logstash + Kibana), уже не раз описанной на Хабре, у администратора имеются инструменты для удобного поиска и отображения всей присутствующей в логах информации. Поэтому ответ на вторую задачу имеется изначально, и остается лишь решить задачу по сбору логов.

Так как в моем случае требованием к системе было отсутствие клиента на серверах, и то, что логи требовалось вытаскивать с Windows-серверов, то в качестве инструмента сбора был выбран родной для Windows — powershell.
Исходя из этого была составлена следующая модель сбора и отображения информации из логов: логи удаленно собираются с серверов powershell-скриптом, после чего складываются в виде файлов на хранилище, далее средствами ELK (Elasticsearch + Logstash + Kibana) происходит их обработка и отображение.

Пример работы всей связки представлен на изображении:



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

В настоящий момент в powershell имеется два способа получения логов с удаленного компьютера:

  • родная команда powershell: Get-EventLog -ComputerName $computer –LogName System
  • получение логов через WMI-запрос: Get-WmiObject -Class win32_NTLogEvent -filter «logfile = 'System'» -ComputerName $computer

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

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

В представленном ниже скрипте имеются несколько неочевидных и сложных моментов:
Сначала описана логика по ограничению промежутка времени для выборки логов, когда требуются логи за последний час, но за час не с момента запроса, а за последний полный час, т.е. начиная с 00 мин. и заканчивая 59 мин.
Второй момент — то, что время в формате WMI отличается от привычного формата, поэтому постоянно требуется конвертация в WMI формат времени и обратно.

ServersEventLogs.ps1
Clear-Host

# импортируем список серверов из Active Directory (для этого в powershell должен быть дополнительно установлен модуль для Active Directory)
import-module activedirectory
$computers = Get-ADComputer -SearchBase "OU=Servers,DC=domain,DC=ru" -Filter * | ForEach-Object {$_.Name} | Sort-Object

# определяем директорию для логирования 
$logdir = "\\storage\Logs\ServersLog\" + $(Get-Date -UFormat "%Y_%m")
# если директория отсутствует, то создаем 
if((Test-Path $logdir) -eq 0) {
	New-Item -ItemType directory $logdir -Force
}

# указываем данные пользователя под которым будут выполнятся команды
$domain = "domain"
$username = "username" 
$password = 'password'

$account = "$domain"+"\"+$($username)
$accountpwd = ConvertTo-SecureString $password -AsPlainText -Force
$credential = New-Object System.Management.Automation.PsCredential($account, $accountpwd)

# для того, чтобы делать выгрузку за предыдущий час, нужно ограничить время за которое лог был сформирован следующим образом: верхний предел - минус час, нижний предел - начало текущего часа.
# получается примерно следующее:
# BiginDate = 08/26/2014 12:00:00
# EndDate = 08/26/2014 13:00:00
# в результате будет выгружен лог созданый в пределах от BiginDate = 08/26/2014 12:00:00 до EndDate = 08/26/2014 13:00:00

$date = Get-Date
Write-Host "Date = $date"
$m = $date.Minute
$s = $date.Second
$begindate = (($date.AddSeconds(-$s)).AddMinutes(-$m)).addHours(-1)
Write-Host "BiginDate = $begindate"
$enddate = ($date.AddSeconds(-$s)).AddMinutes(-$m)
Write-Host "EndDate = $enddate"

# перевод времени в формат WMI
$wmibegindate=[System.Management.ManagementDateTimeConverter]::ToDMTFDateTime($begindate)
Write-Host "WMIBiginDate = $wmibegindate"
$wmienddate=[System.Management.ManagementDateTimeConverter]::ToDMTFDateTime($enddate)
Write-Host "WMIEndDate = $wmienddate"

$logjournals = "System", "Application", "Security"

foreach ($computer in $computers) {
	Write-Host "Processing computer: $computer"
	foreach ($logjournal in $logjournals) {
		Write-Host "Processing log: $logjournal"
		$systemlog = Get-WmiObject -Class win32_NTLogEvent -filter "logfile = '$logjournal' AND (TimeWritten>='$wmibegindate') AND (TimeWritten<'$wmienddate')" -computerName $computer -Credential $credential -ErrorAction SilentlyContinue
		
        foreach ($logstring in $systemlog) {
			$wmitime = $logstring.TimeGenerated
			$time = [System.Management.ManagementDateTimeconverter]::ToDateTime("$wmitime")
			#Write-Host $logtime
				
			$level = $logstring.Type
			#Write-Host "$level"
				
			$journal = $logstring.LogFile
			#Write-Host "$journal"
			
			$category = $logstring.CategoryString
			#Write-Host "$category"
			
			$source = $logstring.SourceName
			#Write-Host "$source"
			
			$message = $logstring.Message
			#Write-Host "$message"
			
			$code = $logstring.EventCode
			#Write-Host "$code"
			
            @{Server="$computer";Time="$time";Level="$level";Journal="$journal";Category="$category";Source="$source";Message="$message";Code="$code"} | ConvertTo-Json -depth 10 -Compress | Out-File "$logdir\$computer-$logjournal.json" -Encoding utf8 -Append
		}
	}
}


По завершении действия скрипта на выходе получаются файлы вида: ComputerName-JournalName.json.
Формат json несколько не соответствует стандарту (отсутствуют открывающие и закрывающие скобки), но парсер Logstash его нормально переваривает и обрабатывает. Для каждого из серверов создается по три файла: ComputerName-System.json ComputerName-Application.json ComputerName-Security.json Так как файлы имеют одинаковый формат, их обработка идеентична.

Ограничить сбор логов определенным журналом можно простым редактированием строчки: $logjournals = «System», «Application», «Security»

Далее в дело вступает Logstash со следующей конфигурацией:

ServersEventLogs.conf
input {

  file {
    type => "ServersLogs"
    discover_interval => 1800
    path => [ "//storage/Logs/ServersLog/*/*.json" ]
    codec => "json"
  }

}


filter {

  date {
    type => "ServersLogs"
    match => [ "Time", "MM/dd/YYYY HH:mm:ss" ]
    locale => "en"
    target => "Logtimestamp"
  }

  mutate {
    gsub => [ "Level", "[ -]", "_" ]
    gsub => [ "Source", "[ -]", "_" ]
    gsub => [ "Server", "[ -]", "_" ]
    remove_field => ["message"]
    remove_field => ["host"] 
  }

}


output {

  elasticsearch {
    embedded => false
    host => "logserver"
    protocol => "http"
    cluster => "windowseventlogs"
    codec => "plain"
    index => "windowseventlogs-%{+YYYY.MM.dd}"
  }

}


Данные заносятся в Elasticsearch, откуда в дальнейшем отображаются с помощью Kibana.

В результате на экран выводится информация (в моем случае за последние 2 суток): о самых проблемных серверах, о самых проблемных сервисах; рисуется график, по которому сразу можно увидеть увеличение количества логов или ошибок в определенный момент времени. Всегда можно выполнить поиск по тексту ошибки или имени пользователя, либо произвести сортировку по уровню или id ошибки.
Дмитрий @sdm
карма
22,0
рейтинг 0,0
Самое читаемое Администрирование

Комментарии (16)

  • +1
    Get-EventLog

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


    Именно поэтому «родной» командой является Get-WinEvent, а не Get-EventLog. И правильно подобрать параметры.

    Но в целом такой метод сбора ужасен, вообще не надо так делать, надо просто воспользоваться специально существующим для таких целей механизмом.
    • 0
      Вы сами пользовались форвардингом большого количества событий (не выборочно, а прямо все события из Security лога) с большого количества раб. станций? Сколько событий/сек может нормально обрабатывать 1 сервер-коллектор?

      • 0
        С рабочих станций не было необходимости, специально стресс-тесты я тоже не устраивал. Но чисто по объемам — с серверов льется несколько гигабайт в день, проблем нет совсем, видимой нагрузки на хосты не создаётся.
        • 0
          А как сливаете — клиенты инициируют отправку или коллектор опрашивает клиентов и загружает логи? Работает ли это все дело, если клиент за НАТом (первый вариант сбора логов, разумеется)?
          • 0
            Стандартный режим, коллектор опрашивает. За NAT у нас клиентов нет, но в целом с точки зрения сети там требование одно — должна быть возможность подключиться через WinRM.
    • 0
      Мне приходилось использовать родной механизм сбора логов, и, к моему сожеланию, вынужден констатировать, что именно он ужасен. Пример:
      Detection of product '%1', feature '%2' failed during request for component '%3'

      Вот именно в таком виде сообщения на хост для сбора логов и приходят, переменные не раскрываются. Скажите, насколько информативен такой подход?
      Именно по этой причине в свое время обратил внимание на продукт Snare for Windows.
      • 0
        Если вы полностью опишете конкретную ситуацию, я, возможно, смогу как-то её прокомментировать. А так это из разряда «товарищи ученые, у нас в подполе раздаётся подземный стук».
        • 0
          Ради теста поднял небольшое окружение из трех серверов, DC, FS, WSUS. Сбор логов настроен на FS, логи собираются с сервера WSUS. Собираем все события из журналов Application, System. На WSUS перезапускаем службу DNS Client, чтобы получить событие, которое отправится на FS. В журнале Forwarded Events получаем следующее:
          The description for Event ID 7036 from source Service Control Manager cannot be found. Either the component that raises this event is not installed on your local computer or the installation is corrupted. You can install or repair the component on the local computer.

          If the event originated on another computer, the display information had to be saved with the event.

          The following information was included with the event:

          DNS Client
          stopped
          44006E007300630061006300680065002F0031000000

          В то время как в событии на WSUS указано всего лишь:
          The DNS Client service entered the stopped state

          Глядя на вот это конкретное событие, переданное на FS, еще можно догадаться, что дело в остановке службы DNS Client. Но сообщения бывают разные, далеко не такие тривиальные. И вот с более сложными уже могут возникнуть проблемы, пример был в комментарии выше.
          С другой стороны, покопался немного на technet. В одном из комментариев было указано следующее, о чем во времена моего печального опыта работы с Windows Event Forwarding я не знал:
          wecutil ss %subscription_name% /cf:events
          После этого события на сервере коллекторе стали приниматься в должном виде.
          Что ж, должен сказать вам спасибо :)
  • 0
    Да, я в курсе, что у microsoft имеется свое решение…
    • 0
      Тогда мне не очень понятна цель изобретения заведомо хуже работающего велосипеда (это я не об обработке логов, а именно о сборе).
      • 0
        Собственно чуть ниже отписал, что winrm нигде не запущен, следовательно решение от microsoft не работает…
  • 0
    В моем случае ни winrm, ни powershell на самих серверах не запущен…
  • 0
    Вообще, спасибо, конечно. Идея хороша.
    Только вот эти танцы с датой ни к чему.
    Я вот так сделал выборку событий за последний час:
    $systemlog = Get-EventLog $logjournal | Where-Object {((Get-date) - $_.TimeGenerated).TotalHours -le 1}
    • 0
      Сорри, сказано же: " 7 раз отмерь, один отрежь." Таки нужны танцы с датой.
      Я такие сделал.
      # Выборка непустых журналов
              $LogJournals = Get-Winevent -ComputerName $Computer -listlog * | `
                                              Where-Object {($_.RecordCount -ge 1)}
      # Выборка сообщений Warning и Error не старше часа
              foreach ($LogJournal in $LogJournals) {
                      $CurrentLog = Get-Winevent -ComputerName $Computer -LogName $LogJournal.LogName | `
                      Where-Object {(((Get-Date) - $_.TimeCreated).TotalHours -le 1) -and `
                              (($_.LevelDisplayName -eq 'Error') -or  ($_.LevelDisplayName -eq 'Warning'))}
              }
      
      • 0
        Перешли от Get-EventLog к Get-WinEvent — уже хорошо. :) Теперь для полноты счастья надо условия отбора из Where по возможности перенести в параметры запроса (-FilterXPath или -FilterHashTable) — сильно ускорит время обработки при хоть сколько-то значительных объемах логов.

        И не используйте Get-Date в цикле — вы же на каждой итерации получаете новую дату, что не только неэффективно, но ещё и приведет к неожиданным для вас результатам в случае длительного выполнения команды. Сделайте, например, $date = (Get-Date).AddHours(-1) и дальше используйте переменную.
  • 0
    Подскажите, а есть какие-нибудь готовые шаблоны для виндовых eventlog-ов?

    Очень хочется видеть более детальную статистику, чем просто группировка по серверам, левелу и коду ошибки.

    Например, входы-выходы юзеров на терминалах и рабочих станциях, сгруппированные по полям логи exchange, логи домен-контроллеров и т.п.

    Пока я взял дефолтовое правило из logstash для syslog и преобразовал к такому виду:
    match => { «message» => "%{SYSLOGTIMESTAMP:syslog_timestamp} %{SYSLOGHOST:syslog_hostname} (%{DATA:event_type}:(?: %{DATA:event_code}):?: %{DATA:event_result} %{GREEDYDATA:syslog_message}|%{GREEDYDATA:syslog_message})" }
    В итоге оно вытаскивает время, имя хоста, тип события, и в большинстве случаев код события. А вот остальные поля парсятся корректно только для Security-Auditing.

    В общем, чувствую, для корректного разбора виндовых логов надо потратить кучу времени на освоение сначала регекспов logstash, а потом на написание нескольких десятков (если не сотен) строк правил.
    А велосипед изобретать не хочется — винда-то у всех есть, значит, под нее и шаблонов должно быть сколько угодно. Однако почему-то гугл более мощных шаблонов не выдает, или я плохо ищу?

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