File server permissions change auditing.
We've had some issues with admins improperly applying permissions in the past, and in recent times as well. Because of this, we've decided that maintaining permissions change logging to determine who it is that's having issues learning how to apply permissions can get some extra training on how to appropriately set file ACEs. The issue with doing this is that it generates ~40GB of compressed Windows logs daily, or closer to 100GB uncompressed. So, how can we use PowerShell to parse through the binary logs, store the info we need, and then get rid of the relatively gigantic evtx files?
Really easily it turns out, with a couple of annoying caveats. Aside from enabling file change/access auditing, parsing the logs on Server 2012 involves just built-in PowerShell cmdlets. But deleting them will require the use of Sysinternals Handle since they seem to linger open in the event viewer at random and we'll need to kill the open handles.
The first thing we need to identify is the event ID we're looking for. Permissions changes trigger a 4670, and that's all I really care about. We're going to use Get-WinEvent to grep through the logs. There are several ways to filter out the garbage we don't care about, but the only one that reliably worked for me was by using FilterXPath, the syntax for that filter is explained here.
There are more complicated filters that we could use to maybe make things easier later, but this gives us a fast filter and results that are easily dealt with. Our XPath filter:
$XPath = @'
*[System[Provider/@Name='Microsoft-Windows-Security-Auditing']]
and
*[System/EventID=4670]
'@
For my server, all the logs now reside on a dedicated drive for just the logs. The drive has NTFS compression turned on, and houses nothing other than the Security and Application logs, their archives, and the output from this script we're building. We set it to L:, like Logs...
The overall plan was originally:
- Search each archive log for each event
- Add the details of those events to a text log
- Delete the archive log
- Repeat
So, first we need to set up our environment a bit. I want to have the logs that we'll be using to have a format that's instantly meaningful to me, so I've set it to write to YYYY-MM-DD.txt. We're also going to need to keep track of all the logs we're going to delete because as I mentioned, they're randomly held open for hours and hours by the EventLog service. We're also going prevent double processing any of the saved logs due to the same stupid thing, so we try to load the previous list and if that fails, assume there's nothing.
$today = (get-date -format g).split()[0]
$logfile = "L:\Permissions Changes\$today.txt"
$DeletableLogs = @()
$DeleteList = "L:\DeletableLogs.txt"
$AdminUsers = @(List,of,people,youre,watching)
try {
$ParsedLogs = get-content $DeleteList -erroraction stop
}
catch [System.Management.Automation.ItemNotFoundException]{
$ParsedLogs = ""}After setting that up, we define what we're looking for and how the output is going to look. This function goes through a list of 4670 event log entries and gets the data we want, and prints it nicely to a text file.
Function LogPermissionChange($PermChanges){
ForEach($PermChange in $PermChanges){
$Change = @{}
# Grab usernames that changed the file
$Change.ChangedBy = $PermChange.properties[1].value.tostring()
#Filter out normal non-admin users
if ($AdminUsers -notcontains $Change.ChangedBy){continue}
# Grab the filename/foldername changed
$Change.FileChanged = $PermChange.properties[6].value.tostring()
#Ignore temporary files
if ($Change.FileChanged.EndsWith(".tmp")){continue}
elseif ($Change.FileChanged.EndsWith(".partial")){continue}
$Change.MadeOn = $PermChange.TimeCreated.tostring()
$Change.OriginalPermissions = $PermChange.properties[8].value.tostring()
$Change.NewPermissions = $PermChange.properties[9].value.tostring()
write-output "{" >> $logfile
write-output ("Changed By : "+ $Change.ChangedBy) >> $logfile
write-output ("File Changed : "+ $Change.FileChanged) >> $logfile
write-output ("Change Made : "+ $Change.MadeOn) >> $logfile
write-output ("Original Permissions :
"+ $Change.OriginalPermissions) >> $logfile
write-output ("New Permissions :
"+ $Change.NewPermissions) >> $logfile
"}
" >> $logfile
}
}
Then we do the actual log crawl, and call the above on each log:
GCI -include Archive-Security*.evtx -path L:\Security\ -recurse | ForEach-Object{
$log = $_
if ($ParsedLogs -contains $log){
return
}
Try{
$PermChanges = Get-WinEvent -Path $_ -FilterXPath $XPath -ErrorAction Stop
}
Catch [Exception]{
if ($_.Exception -match "No events were found that match the specified selection criteria."){
}
else {
Throw $_
}
}
LogPermissionChange($PermChanges)
$PermChanges = $Null
$DeletableLogs += $_
}
Then try to clean things up, where possible, and exit.
foreach ($log in $DeletableLogs){
$Timer = 0
Try{
remove-item $log -ErrorAction Stop
}
Catch [Exception]{
write-output $log.FullName >> $DeleteList
}
}
exit
Originally, I didn't catch any errors during the delete, then I tried 5 times and gave up, then 10. However, that seemed to only ever clear about 1/3 of the archived event logs, and soon enough our drive was out of space, nothing was getting logged and nobody was happy.
Fine, stupid Windows. I'll get fancy. Thanks to someone over on StackOverflow I received some code that should help with this. I already have some portion of the entire Sysinternals suite installed across most of our servers, and Handle is of course already on our file server.
After a few iterations of the original script failed to give me the results I wanted (not holding 100GB of compressed logs forever), I ended up remembering that I am not so smart and to do things easily since I don't actually have to do them. The script to clean things up opens the list of processed logs, goes through and tries to delete them, if they're still open it tries to unlock them with Handle and delete them again then sends anything it can't delete back to the list for next time.
$StillToDelete = @()
$DeleteList = "L:\DeletableLogs.txt"
$DeletableLogs = get-content $DeleteList
Function Close-LockedFile{
Param(
[Parameter(Mandatory=$true,ValueFromPipeline=$true)][String[]]$Filename
)
Begin{
$HandleApp = 'C:\sysinternals\Handle64.exe'
If(!(Test-Path $HandleApp)){Write-Host "Handle.exe not found at $HandleApp`nPlease download it from www.sysinternals.com and save it in the afore mentioned location.";break}
}
Process{
$HandleOut = Invoke-Expression ($HandleApp+' '+$Filename)
$Locks = $HandleOut |?{$_ -match "(.+?)\s+pid: (\d+?)\s+type: File\s+(\w+?): (.+)\s*$"}|%{
[PSCustomObject]@{
'AppName' = $Matches[1]
'PID' = $Matches[2]
'FileHandle' = $Matches[3]
'FilePath' = $Matches[4]
}
}
ForEach($Lock in $Locks){
Invoke-Expression ($HandleApp + " -p " + $Lock.PID + " -c " + $Lock.FileHandle + " -y") | Out-Null
If ( ! $LastexitCode ) { "Successfully closed " + $Lock.AppName + "'s lock on " + $Lock.FilePath}
}
}
}
foreach ($log in $DeletableLogs) {
try {
remove-item $log -ErrorAction stop
}
catch [System.Management.Automation.ItemNotFoundException]{
continue
}
catch [system.IO.IOException]{
try {
Close-LockedFile $log
remote-item $log -ErrorAction stop
}
catch [exception]{
$StillToDelete += $log
}
}
}
write-output $StillToDelete > $DeleteList
exit
The full scripts are, as always, available on my Scripts page.