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

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

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

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

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!

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

Errors are also logged as well if something happens.

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.

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.

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.

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.

Event 4014 lists the command being run.

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.

And when we run the fuction:

Do-Something -Stuff 123

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:

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

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

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:

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

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

Now for the rest of the command.

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()

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

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.

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!