Когда наше файловое хранилище разменяло третий терабайт, все чаще наш отдел стал получать просьбы выяснить, кто удалил важный документ или целую папку с документами. Нередко это происходит по чьему-то злому умыслу. Бэкапы — это хорошо, но страна должна знать своих героев. А молоко вдвойне вкусней, когда мы можем написать его на PowerShell.
Пока разбирался, решил записать для коллег по цеху, а потом подумал, что может пригодиться кому-то еще. Материал получился смешанный. Кто-то найдет для себя готовое решение, кому-то пригодятся несколько неочевидные методы работы с PowerShell или планировщиком задач, а кто-то проверит на быстродействие свои скрипты.
- Во-первых, время генерации отчета за четыре часа на 2-терабайтном хранилище, с которым одновременно работает около 200 человек, составило около пяти минут. И это притом, что лишнего у нас в логи не пишется. Это меньше, чем у Deks, но больше, чем хотелось бы, потому что…
- Во-вторых, все то же самое нужно было реализовать еще на двадцати серверах, гораздо менее производительных, чем основной.
- В-третьих, вызывал вопросы график запуска генерации отчетов.
- И в-четвертых, хотелось исключить себя из процесса доставки собранной информации конечным потребителям (читай: автоматизировать, чтобы мне с этим вопросом больше не звонили).
Краткий дискурс: При включенном аудите файловой системы в момент удаления файла в журнале безопасности создаются два события, с кодами 4663 и, следом, 4660. Первое записывает попытку запроса доступа на удаление, данные о пользователе и пути к удаляемому файлу, а второе — фиксирует свершившийся факт удаления. У событий есть уникальный идентификатор EventRecordID, который отличается на единицу у этих двух событий.
Ниже приведен исходный скрипт, собирающий информацию об удаленных файлах и пользователях, их удаливших.
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 |
$time = (get-date) - (new-timespan -min 240) $Events = Get-WinEvent -FilterHashtable @{LogName="Security";ID=4660;StartTime=$time} | Select TimeCreated,@{n="Запись";e={([xml]$_.ToXml()).Event.System.EventRecordID}} |sort Запись $BodyL = "" $TimeSpan = new-TimeSpan -sec 1 foreach($event in $events){ $PrevEvent = $Event.Запись $PrevEvent = $PrevEvent - 1 $TimeEvent = $Event.TimeCreated $TimeEventEnd = $TimeEvent+$TimeSpan $TimeEventStart = $TimeEvent- (new-timespan -sec 1) $Body = Get-WinEvent -FilterHashtable @{LogName="Security";ID=4663;StartTime=$TimeEventStart;EndTime=$TimeEventEnd} |where {([xml]$_.ToXml()).Event.System.EventRecordID -match "$PrevEvent"}|where{ ([xml]$_.ToXml()).Event.EventData.Data |where {$_.name -eq "ObjectName"}|where {($_.'#text') -notmatch ".*tmp"} |where {($_.'#text') -notmatch ".*~lock*"}|where {($_.'#text') -notmatch ".*~$*"}} |select TimeCreated, @{n="Файл_";e={([xml]$_.ToXml()).Event.EventData.Data | ? {$_.Name -eq "ObjectName"} | %{$_.'#text'}}},@{n="Пользователь_";e={([xml]$_.ToXml()).Event.EventData.Data | ? {$_.Name -eq "SubjectUserName"} | %{$_.'#text'}}} if ($Body -match ".*Secret*"){ $BodyL=$BodyL+$Body.TimeCreated+"`t"+$Body.Файл_+"`t"+$Body.Пользователь_+"`n" } } $Month = $Time.Month $Year = $Time.Year $name = "DeletedFiles-"+$Month+"-"+$Year+".txt" $Outfile = "serverServerLogFilesDeletedFilesLog"+$name $BodyL | out-file $Outfile -append |
С помощью команды Measure-Command получили следующее:
1 2 3 4 5 |
Measure-Command { ... } | Select-Object TotalSeconds | Format-List ... TotalSeconds : 313,6251476 |
Многовато, на вторичных ФС будет дольше. Сходу очень не понравился десятиэтажный пайп, поэтому для начала я его структурировал:
1 2 3 4 5 6 |
Get-WinEvent -FilterHashtable @{ LogName="Security";ID=4663;StartTime=$TimeEventStart;EndTime=$TimeEventEnd } ` | Where-Object {([xml]$_.ToXml()).Event.System.EventRecordID -match "$PrevEvent"} ` | Where-Object {([xml]$_.ToXml()).Event.EventData.Data ` | Where-Object {$_.name -eq "ObjectName"} ` | Where-Object {($_.'#text') -notmatch ".*tmp"} ` | Where-Object {($_.'#text') -notmatch ".*~lock*"} ` | Where-Object {($_.'#text') -notmatch ".*~$*"} } | Select-Object TimeCreated, @{ n="Файл_"; e={([xml]$_.ToXml()).Event.EventData.Data `| Where-Object {$_.Name -eq "ObjectName"} `| ForEach-Object {$_.'#text'} } }, @{ n="Пользователь_"; e={([xml]$_.ToXml()).Event.EventData.Data `| Where-Object {$_.Name -eq "SubjectUserName"} `| ForEach-Object {$_.'#text'} } } |
Получилось уменьшить этажность пайпа и убрать перечисления Foreach, а заодно сделать код более читаемым, но большого эффекта это не дало, разница в пределах погрешности:
1 2 3 4 5 6 7 8 9 10 11 12 13 |
Measure-Command { $time = (Get-Date) - (New-TimeSpan -min 240) $Events = Get-WinEvent -FilterHashtable @{LogName="Security";ID=4660;StartTime=$time}` | Select TimeCreated,@{n="EventID";e={([xml]$_.ToXml()).Event.System.EventRecordID}}` | Sort-Object EventID $DeletedFiles = @() $TimeSpan = new-TimeSpan -sec 1 foreach($Event in $Events){ $PrevEvent = $Event.EventID $PrevEvent = $PrevEvent - 1 $TimeEvent = $Event.TimeCreated $TimeEventEnd = $TimeEvent+$TimeSpan $TimeEventStart = $TimeEvent- (New-TimeSpan -sec 1) $DeletedFiles += Get-WinEvent -FilterHashtable @{LogName="Security";ID=4663;StartTime=$TimeEventStart;EndTime=$TimeEventEnd} ` | Where-Object {`([xml]$_.ToXml()).Event.System.EventRecordID -match "$PrevEvent" `-and (([xml]$_.ToXml()).Event.EventData.Data ` | where {$_.name -eq "ObjectName"}).'#text' ` -notmatch ".*tmp$|.*~lock$|.*~$*" } ` | Select-Object TimeCreated, @{n="FilePath";e={(([xml]$_.ToXml()).Event.EventData.Data `| Where-Object {$_.Name -eq "ObjectName"}).'#text'} }, @{n="UserName";e={(([xml]$_.ToXml()).Event.EventData.Data `| Where-Object {$_.Name -eq "SubjectUserName"}).'#text'} } ` } } | Select-Object TotalSeconds | Format-List $DeletedFiles | Format-Table UserName,FilePath -AutoSize ... TotalSeconds : 302,6915627 |
Пришлось немного подумать головой. Какие операции занимают больше всего времени? Можно было бы натыкать еще десяток Measure-Command, но в общем-то в данном случае и так очевидно, что больше всего времени тратится на запросы в журнал (это не самая быстрая процедура даже в MMC) и на повторяющиеся конвертации в XML (к тому же, в случае с EventRecordID это и вовсе необязательно). Попробуем сделать и то и другое по одному разу, а заодно исключить промежуточные переменные:
1 2 3 4 5 6 |
Measure-Command { $time = (Get-Date) - (New-TimeSpan -min 240) $Events = Get-WinEvent -FilterHashtable @{LogName="Security";ID=4660,4663;StartTime=$time}`| Select TimeCreated,ID,RecordID,@{n="EventXML";e={([xml]$_.ToXml()).Event.EventData.Data}}`| Sort-Object RecordID $DeletedFiles = @() foreach($Event in ($Events | Where-Object {$_.Id -EQ 4660})){$DeletedFiles += $Events `| Where-Object {` $_.Id -eq 4663 ` -and $_.RecordID -eq ($Event.RecordID - 1) ` -and ($_.EventXML | where Name -eq "ObjectName").'#text'` -notmatch ".*tmp$|.*~lock$|.*~$"} `| Select-Object `@{n="RecordID";e={$Event.RecordID}}, TimeCreated,@{n="ObjectName";e={($_.EventXML | where Name -eq "ObjectName").'#text'}},@{n="UserName";e={($_.EventXML | where Name -eq "SubjectUserName").'#text'}} } } | Select-Object TotalSeconds | Format-List $DeletedFiles | Sort-Object UserName,TimeDeleted | Format-Table -AutoSize -HideTableHeaders ... TotalSeconds : 167,7099384 |
А вот это уже результат. Ускорение практически в два раза!
Автоматизируем
Порадовались, и хватит. Три минуты — это лучше, чем пять, но как лучше всего запускать скрипт? Раз в час? Так могут ускользнуть записи, которые появляются одновременно с запуском скрипта. Делать запрос не за час, а за 65 минут? Тогда записи могут повторяться. Да и искать потом запись о нужном файле среди тысячи логов — мутор. Писать раз в сутки? Ротация логов забудет половину. Нужно что-то более надежное. В комментариях к статье Deks кто-то говорил о приложении на дотнете, работающем в режиме службы, но это, знаете, из разряда «There are 14 competing standards»…
В планировщике заданий Windows можно создать триггер на событие в системном журнале. Вот так:
Отлично! Скрипт будет запускаться ровно в момент удаления файла, и наш журнал будет создаватья в реальном времени! Но наша радость будет неполной, если мы не сможем определить, какое событие нам нужно записать в момент запуска. Нам нужна хитрость. Их есть у нас! Недолгий гуглинг показал, что по триггеру «Событие» планировщик может передавать исполняемому файлу информацию о событии. Но делается это, мягко говоря, неочевидно. Последовательность действий такая:
- Создать задачу с триггером типа «Event»;
- Экспортировать задачу в формат XML (через консоль MMC);
- Добавить в ветку «EventTrigger» новую ветвь «ValueQueries» с элементами, описывающими переменные:
1<eventtrigger> ... <valuequeries><value name="eventRecordID">Event/System/EventRecordID</value></valuequeries></eventtrigger>
где «eventRecordID» — название переменной, которую можно будет передать скрипту, а «Event/System/EventRecordID» — элемент схемы журнала Windows, с которой можно ознакомиться по ссылке внизу статьи. В данном случае это элемент с уникальным номером события.
- Импортировать задание обратно в планировщик.
Но мы же не хотим натыкивать все это мышкой на 20 серверах, верно? Нужно автоматизировать. К сожалению, PowerShell не всесилен, и командлет New-ScheduledTaskTrigger пока что не умеет создавать триггеры типа Event. Поэтому применим чит-код и создадим задачу через COM-объект (пока что достаточно часто приходится прибегать к COM, хотя штатные командлеты умеют все больше и больше c каждой новой версией PS):
1 2 3 4 |
$scheduler = New-Object -ComObject "Schedule.Service" $scheduler.Connect("localhost") $rootFolder = $scheduler.GetFolder("") $taskDefinition = $scheduler.NewTask(0) |
Нужно обязательно разрешить одновременный запуск нескольких экземпляров, а также, как мне кажется, стоит запретить ручной запуск и задать лимит времени выполнения:
1 2 3 4 5 6 |
$taskDefinition.Settings.Enabled = $True $taskDefinition.Settings.Hidden = $False $taskDefinition.Principal.RunLevel = 0 # 0 - обычные привилегии, 1 - повышенные привилегии $taskDefinition.Settings.MultipleInstances = $True $taskDefinition.Settings.AllowDemandStart = $False $taskDefinition.Settings.ExecutionTimeLimit = "PT5M" |
Создадим триггер типа 0 (Event). Далее задаем XML-запрос для получения нужных нам событий. Код XML-запроса можно получить в консоли MMC «Журнал событий», выбрав необходимые параметры и переключившись на вкладку «XML»:
1 2 |
$Trigger = $taskDefinition.Triggers.Create(0) $Trigger.Subscription = '<querylist><query id="0" path="Security"><select path="Security"> *[System[Provider[@Name="Microsoft-Windows-Security-Auditing"] and EventID=4660]] </select></query></querylist>' |
Главная хитрость: указываем переменную, которую нужно передать скрипту.
1 |
$Trigger.ValueQueries.Create("eventRecordID", "Event/System/EventRecordID") |
Собственно, описание выполняемой команды:
1 2 3 4 |
$Action = $taskDefinition.Actions.Create(0) $Action.Path = 'PowerShell.exe' $Action.WorkingDirectory = 'C:Temp' $Action.Arguments = '.ParseDeleted.ps1 $(eventRecordID) C:TempDeletionLog.log' |
И — взлетаем!
1 |
$rootFolder.RegisterTaskDefinition("Log Deleted Files", $taskDefinition, 6, 'SYSTEM', $null, 5) |
«Концепция поменялась»
Вернемся к скрипту для записи логов. Теперь нам не надо получать все события, а нужно доставать одно-единственное, да еще переданное в качестве аргумента. Для этого мы допишем заголовки, превращающие скрипт в командлет с параметрами. До кучи — сделаем возможным изменять путь к логу «на лету», авось, пригодится:
1 2 3 4 5 |
[CmdletBinding()] Param( [Parameter(Mandatory=$True,Position=1)]$RecordID, [Parameter(Mandatory=$False,Position=2)]$LogPath = "C:DeletedFiles.log" ) |
Дальше возникает нюанс: до сего момента мы получали события командлетом Get-WinEvent и фильтровали параметром -FilterHashtable. Он понимает ограниченный набор атрибутов, в который не входит EventRecordID. Поэтому фильтровать мы будем через параметр -FilterXml, мы же теперь и это умеем!
1 2 3 |
$XmlQuery="<querylist><query id="0" path="Security"><select path="Security">*[System[(EventID=4663) and (EventRecordID=$($RecordID - 1))]]</select></query></querylist>" $Event = Get-WinEvent -FilterXml $XmlQuery ` | Select TimeCreated,ID,RecordID,@{n="EventXML";e={([xml]$_.ToXml()).Event.EventData.Data}}` |
Теперь нам больше не нужно перечисление Foreach-Object, поскольку обрабатывается всего одно событие. Не два, потому что событие с кодом 4660 используется только для того, чтобы инициировать скрипт, полезной информации оно в себе не несет. Помните, в начале я хотел, чтобы пользователи могли без моего участия узнатьзлодея? Так вот, в случае, если файл удален в папке документов какого-либо отдела — пишем лог также в корень папки отдела.
1 2 3 4 5 6 7 8 9 10 11 |
$EventLine = "" if (($Event.EventXML | where Name -eq "ObjectName").'#text' -notmatch ".*tmp$|.*~lock$|.*~$"){ $EventLine += "$($Event.TimeCreated)`t" $EventLine += "$($Event.RecordID)`t" $EventLine += ($Event.EventXML | where Name -eq "SubjectUserName").'#text' + "`t" $EventLine += ($ObjectName = ($Event.EventXML | where Name -eq "ObjectName").'#text') if ($ObjectName -match "DocumentsПодразделения"){ $OULogPath = $ObjectName ` -replace "(.*Documents\Подразделения\[^\]*\)(.*)",'$1DeletedFiles.log' if (!(Test-Path $OULogPath)){ "DeletionDate`tEventID`tUserName`tObjectPath"| Out-File -FilePath $OULogPath } $EventLine | Out-File -FilePath $OULogPath -Append } if (!(Test-Path $LogPath)){ "DeletionDate`tEventID`tUserName`tObjectPath" | Out-File -FilePath $LogPath } $EventLine | Out-File -FilePath $LogPath -Append } |
Итоговый командлет
Ну вот, кусочки нарезаны, осталось собрать все воедино и еще чуть-чуть оптимизировать. Получится как-то так:
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 |
[CmdletBinding()] Param( [Parameter(Mandatory=$True,Position=1,ParameterSetName='logEvent')][int]$RecordID, [Parameter(Mandatory=$False,Position=2,ParameterSetName='logEvent')] [string]$LogPath = "$PSScriptRootDeletedFiles.log", [Parameter(ParameterSetName='install')][switch]$Install ) if ($Install) { $service = New-Object -ComObject "Schedule.Service" $service.Connect("localhost") $rootFolder = $service.GetFolder("") $taskDefinition = $service.NewTask(0) $taskDefinition.Settings.Enabled = $True $taskDefinition.Settings.Hidden = $False $taskDefinition.Settings.MultipleInstances = $True $taskDefinition.Settings.AllowDemandStart = $False $taskDefinition.Settings.ExecutionTimeLimit = "PT5M" $taskDefinition.Principal.RunLevel = 0 $trigger = $taskDefinition.Triggers.Create(0) $trigger.Subscription = ' <querylist><query id="0" path="Security"><select path="Security">*[System[Provider[@Name="Microsoft-Windows-Security-Auditing"] and EventID=4660]] </select></query></querylist>' $trigger.ValueQueries.Create("eventRecordID", "Event/System/EventRecordID") $Action = $taskDefinition.Actions.Create(0) $Action.Path = 'PowerShell.exe' $Action.WorkingDirectory = $PSScriptRoot $Action.Arguments = '.' + $MyInvocation.MyCommand.Name + ' $(eventRecordID) ' + $LogPath $rootFolder.RegisterTaskDefinition("Log Deleted Files", $taskDefinition, 6, 'SYSTEM', $null, 5) } else { $XmlQuery="<querylist><query id="0" path="Security"><select path="Security">*[System[(EventID=4663) and (EventRecordID=$($RecordID - 1))]]</select></query></querylist>" $Event = Get-WinEvent -FilterXml $XmlQuery ` | Select TimeCreated,ID,RecordID,@{n="EventXML";e={([xml]$_.ToXml()).Event.EventData.Data}} if (($ObjectName = ($Event.EventXML | where Name -eq "ObjectName").'#text') `-notmatch ".*tmp$|.*~lock$|.*~$"){ $EventLine = "$($Event.TimeCreated)`t" + "$($Event.RecordID)`t" ` + ($Event.EventXML | where Name -eq "SubjectUserName").'#text' + "`t" `+ $ObjectName if ($ObjectName -match ".*Documents\Подразделения\[^\]*\"){ $OULogPath = $Matches[0] + 'DeletedFiles.log' if (!(Test-Path $OULogPath)){"DeletionDate`tEventID`tUserName`tObjectPath"| Out-File -FilePath $OULogPath } $EventLine | Out-File -FilePath $OULogPath -Append } if (!(Test-Path $LogPath)){ "DeletionDate`tEventID`tUserName`tObjectPath" | Out-File -FilePath $LogPath } $EventLine | Out-File -FilePath $LogPath -Append } } |
Осталось поместить скрипт в удобное для вас место и запустить с ключом -Install.
Теперь сотрудники любого отдела могут в реальном времени видеть, кто, что и когда удалил из их каталогов. Отмечу, что я не стал рассматривать здесь права доступа к файлам логов (чтобы злодей не мог их удалить) и ротацию. Структура и права доступа к каталогам на нашем файлере тянут на отдельную статью, а ротация в какой-то степени усложнит поиск нужной строки.
https://habr.com/ru/post/238469/
Ваш комментарий будет первым