More New Stuff in PowerShell V5: Extra PowerShell Auditing

With the latest Preview release of PowerShell V5 July (X86, X64), we get some extra capabilities for auditing PowerShell script tracing. Since PowerShell V3, we have had the capability of Module Logging in PowerShell, meaning that we can track the commands that are being run for specified PowerShell modules in the event logs. As a refresher, I will show you both of the two ways that this can be enabled and what the expected event logs will look like.

Module Loading

This is the manual approach, but allows you to track the execution of the commands in the PowerShell console. This has to be done for each module that you want this enabled for and is only valid for the current session. You can use either Import-Module or Get-Module and list the module names in parenthesis and specify the LogPipelineExecutionDetails = $True. We can quickly look at the Microsoft.PowerShell modules to see if any of those have logging enabled.

Get-Module Microsoft.* | 
Select Name, LogPipelineExecutionDetails

 

image

None of these are enabled…yet. Time to make that change.

Get-Module Microsoft.* | ForEach {
    $_.LogPipelineExecutionDetails = $True
}

image

All right! Now we are set to run some commands and see what happens in the event logs.

Note: Here is how to do it using Import-Module:

(Import-Module ActiveDirectory).LogPipelineExecutionDetails = $True

After some various commands such as Get-ChildItem, we can look at the event logs to see that all of this has been logged

image

Ok, this is a little hard to see unless you click on the image, but what we are looking at is the Windows PowerShell event log and the Pipeline Execution Details (ID 800) which shows not only the commands that were run, but also the parameters and who actually ran the command!

image

Ok, this is PowerShell so obviously I need to do this the ‘proper way’.

Get-WinEvent -FilterHashtable @{LogName='Windows PowerShell';Id ='800'} -MaxEvents 1 | 
Select -Expand Message

 

image

Errors are also logged as well if something happens.

image

Pretty cool, right? I mentioned that there were two ways to accomplish this and that other way is via Group Policy.

Group Policy

You can either set this via Computer and/or User policy under Administrative Templates/Windows Components/Windows PowerShell under Turn On Module Logging.

Once you enable the policy setting, you can then specify the modules that you wish to track the execution of commands.

image

SNAGHTML14756c46

SNAGHTML147767b8

Once that is done and the GPO has been applied to the systems, you will start seeing the new event logs pop in.

One thing to keep in mind is that the logs may start churning rather hard, so you need to make sure that you are archiving the logs to ensure that you do not miss anything important or have some sort of event forwarding capability to send these logs off to a syslog server.

Latest Script Logging Enhancements

So I have talked about all of this stuff that has been around for a while for a reason. The PowerShell team has improved on this logging by now allowing more detailed logging of scriptblocks to the PowerShell ETW log.

There are a couple of Environmental Variables that need to be configured in order to achieve the enhanced logging. Those are:

  • PSLogScriptBlockExecution
    • When this environment variable exists (its value doesn’t matter), Windows PowerShell logs the text of scripts and script blocks the first time they are seen.
  • PSLogScriptBlockExecutionVerbose
    • When this environment variable exists (its value doesn’t matter), Windows PowerShell logs execution details (begin and end) when logged script blocks are invoked.

Group policy would be the idea approach for this. This is available for both User and Computer policies, so it is up to you which one (or both) that you want to use.

SNAGHTML1486ac4a

These events are not  located in the Windows PowerShell event log, but are located in the Microsoft/Windows/PowerShell/Operational ETW log. The following event IDs correspond to the type of logging you enabled:

  • PSLogScriptBlockExecution
    • Event ID 4104
  • PSLogScriptBlockExecutionVerbose
    • Event ID 4105 (Starting scriptblock) and 4106 (Completing scriptblock)

Note: This does log for things ran through the ISE just like it will for the console.

Now I will run a similar command as I did earlier so we can see what else is being logged.

Get-ChildItem -Path C:\DSC -Filter *.mof -Recurse

Now let’s check out those logs.

image

With that command, we kicked off 36 logs. If you notice, most of the logs are a result of setting PSLogScriptBlockExecutionVerbosewith events 4105 and 4106 tracking each scriptblock creation.

image

image

Event 4014 lists the command being run.

image

Nothing that impressive just yet, but notice that we do not have to specify a specific module to track. Now let’s compile a function on the fly and let it run.

Function Do-Something { 
    Param ($Stuff) 
    Write-Output $Stuff
}

We can see under EventID 4104 that it is compiling the scriptblock.

image

And when we run the fuction:

Do-Something -Stuff 123

image

 

Now I am going to use the example from the July ReadMe file to show an obfuscated command and how it is tracked both in the Windows PowerShell log and the ETW logs.

First the PowerShell log:

Build the function out:

function SuperDecrypt {
    param($script)

    $bytes = [Convert]::FromBase64String($script)
                
    ## XOR “encryption”
    $xorKey = 0x42
    for($counter = 0; $counter -lt $bytes.Length; $counter++)
    {
        $bytes[$counter] = $bytes[$counter] -bxor $xorKey
    }

    [System.Text.Encoding]::Unicode.GetString($bytes)
}

Check the PowerShell log:

image

Well, that’s not off to a good start. Now let’s run the function.

$decrypted = SuperDecrypt "FUIwQitCNkInQm9CCkItQjFCNkJiQmVCEkI1QixCJkJlQg=="
Invoke-Expression $decrypted  

 

image

image

Ok, we got a little bit of info only because I was tracking the modules that use Write-Host and Invoke-Expression. If I didn’t have this enabled, well, this wouldn’t have been easy to catch.

Now let’s try this using the enhanced logging:

Build the function:

image

Here we can see the function being created in the ETW logs. Now let’s run it as well.

image

Oh look, it caught the variable being created as well!

Now for the rest of the command.

image

image

It doesn’t give you the pipeline binding that you would see with the PowerShell event log, but it does give you enough information to know what is happening here.

I wanted to do a little more testing just to see what else was logged. Here is similar code but instead I invoked the code as a scriptblock instead of using Invoke-Expression.

{$decrypted}.Invoke()

image

While this would have never been caught through module logging, it was caught here. Although it didn’t give us the contents of $decrypted, it at least showed that something was being invoked.

Last thing to try out: running an encoded command through PowerShell.exe.

$command = '[console]::WriteLine("Something malicious happening!")'
$bytes = [System.Text.Encoding]::Unicode.GetBytes($command)
$encodedCommand = [Convert]::ToBase64String($bytes)

$EncodedCommand produces this:

WwBjAG8AbgBzAG8AbABlAF0AOgA6AFcAcgBpAHQAZQBMAGkAbgBlACgAIgBTAG8AbQBlAHQAaABpAG4AZwAgAG0AYQBsAGkAYwBpAG8AdQBzACAAaABhAHAAcABlAG4AaQBuAGcAIQAiACkA

 

Now I run PowerShell.exe from the Run menu with this encoded command.

powershell.exe -encodedcommand WwBjAG8AbgBzAG8AbABlAF0AOgA6AFcAcgBpAHQAZQBMAGkAbgBlACgAIgBTAG8AbQBlAHQAaABpAG4AZwAgAG0AYQBsAGkAYwBpAG8AdQBzACAAaABhAHAAcABlAG4AaQBuAGcAIQAiACkA

image

It’s right after EventID 40962 that we see the event that shows the encoded command being created prior to running.

And I do get this in the PowerShell event log only if I have Module Logging enabled through Group Policy.

image

As with the PowerShell event log, this will generate A LOT of events, especially if you enabled PSLogScriptBlockExecutionVerbose as it really pumps out the events. But there you go, a couple more ways to audit PowerShell usage that begin in PowerShell V5 July Preview!

About Boe Prox

Microsoft Cloud and Datacenter MVP working as a SQL DBA.
This entry was posted in powershell, V5 and tagged , , , . Bookmark the permalink.

8 Responses to More New Stuff in PowerShell V5: Extra PowerShell Auditing

  1. Pingback: Windows Event Forwarding/Collector Resources - Cyber Security And Non Profits

  2. Pingback: Friday Five - August 29, 2014

  3. Pingback: MVP top tips: Columns in Remote Access Management, SCOM 2012 Health Script, PowerShell V5, Associations in SharePoint and Office 365, Sharing Images Phone 8.1 apps | Lions News Archive

  4. Pingback: MVP top tips: Columns in Remote Access Management, SCOM 2012 Health Script, PowerShell V5, Associations in SharePoint and Office 365, Sharing Images Phone 8.1 apps - Canadian IT Manager's Blog - Site Home - TechNet Blogs

  5. Pingback: Friday Five – August 29, 2014 | CmdExec Technology News

  6. Pingback: Friday Five - August 29, 2014 - The Microsoft MVP Award Program Blog - Site Home - MSDN Blogs

  7. Another Great post! keep the awesome work! 🙂

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s