Return to
Portfolio

100.2. Logging PowerShell Activity

Recent versions of Windows PowerShell provide several features for logging of activity from PowerShell sessions. NXLog can be configured to collect and parse these logs.

In addition to the sections below, see Securing PowerShell in the Enterprise, Greater Visibility Through PowerShell Logging, and PowerShell ♥ the Blue Team. Also see the Command line process auditing article on Microsoft Docs and the Sysmon chapter, both of which can be used to generate events for command line process creation (but not for commands executed through the PowerShell engine).

100.2.1. Module Logging

Module logging, available since PowerShell 3, logs pipeline execution events for specified PowerShell modules. This feature writes Event ID 4103 events to the Microsoft-Windows-PowerShell/Operational channel.

Module logging can be enabled by setting the LogPipelineExecutionDetails property of a module to True. Or this property can be enabled for selected modules through Group Policy as follows.

  1. Open the Group Policy MMC snapin (gpedit.msc).

  2. Go to Computer Configuration  Administrative Templates  Windows Components  Windows PowerShell and open the Turn on Module Logging setting.

    Finding the Module Logging policy
  3. Select Enabled. Then click the Show… button and enter the modules for which to enable logging. Use an asterisk (*) to enable logging for all modules.

    Configuring the Module Logging policy
Example 422. Collecting Module Logging Events

This configuration collects all events with ID 4103 from the Windows PowerShell Operational channel. The logs are then converted to Syslog-encapsulated JSON and forwarded via TCP.

nxlog.conf [Download file]
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
<Extension _json>
    Module  xm_json
</Extension>

<Extension _syslog>
    Module  xm_syslog
</Extension>

<Input module_logging>
    Module  im_msvistalog
    <QueryXML>
        <QueryList>
            <Query Id="0" Path="Microsoft-Windows-PowerShell/Operational">
                <Select Path="Microsoft-Windows-PowerShell/Operational">
                    *[System[EventID=4103]]</Select>
            </Query>
        </QueryList>
    </QueryXML>
    Exec    $Message = to_json(); to_syslog_bsd();
</Input>

<Output tcp>
    Module  om_tcp
    Host    10.12.1.1
    Port    514
</Output>

100.2.2. Script Block Logging

PowerShell 5 introduces script block logging, which records the content of all script blocks that are processed. Events with ID 4104 are written to the Microsoft-Windows-PowerShell/Operational channel. Start and stop events can also be enabled; these events have IDs 4105 and 4106.

Script block logging can be configured through Group Policy as follows.

  1. Open the Group Policy MMC snapin (gpedit.msc).

  2. Go to Computer Configuration  Administrative Templates  Windows Components  Windows PowerShell and open the Turn on PowerShell Script Block Logging setting.

    Finding the Script Block Logging policy
  3. Select Enabled. Optionally, check the Log script block invocation start/stop events option (this will generate a high volume of event logs).

    Configuring the Script Block Logging policy
Example 423. Collecting Script Block Logging Events

The following configuration collects events with IDs 4104, 4105, and 4106 from the Windows PowerShell Operational channel. Verbose level events are excluded.

nxlog.conf [Download file]
1
2
3
4
5
6
7
8
9
10
11
12
13
<Input script_block_logging>
    Module  im_msvistalog
    <QueryXML>
        <QueryList>
            <Query Id="0" Path="Microsoft-Windows-PowerShell/Operational">
                <Select Path="Microsoft-Windows-PowerShell/Operational">
                    *[System[(Level=0 or Level=1 or Level=2 or Level=3 or Level=4)
                             and ((EventID &gt;= 4104 and EventID &lt;= 4106))]]
                </Select>
            </Query>
        </QueryList>
    </QueryXML>
</Input>

100.2.3. Transcription

PowerShell provides "over-the-shoulder" transcription of PowerShell sessions with the Start-Transcript cmdlet. With PowerShell 5, system-wide transcription can be enabled via Group Policy; this is equivalent to calling the Start-Transcript cmdlet on each PowerShell session. Transcriptions are written to the current user’s Documents directory unless a system-level output directory is set in the policy settings.

Log Sample (With Invocation Headers Enabled)
**********************
Windows PowerShell transcript start
Start time: 20171030223248
Username: WIN-FT17VBNL4B2\Administrator
RunAs User: WIN-FT17VBNL4B2\Administrator
Machine: WIN-FT17VBNL4B2 (Microsoft Windows NT 10.0.14393.0)
Host Application: C:\Windows\system32\WindowsPowerShell\v1.0\PowerShell.exe
Process ID: 4268
PSVersion: 5.1.14393.1770
PSEdition: Desktop
PSCompatibleVersions: 1.0, 2.0, 3.0, 4.0, 5.0, 5.1.14393.1770
BuildVersion: 10.0.14393.1770
CLRVersion: 4.0.30319.42000
WSManStackVersion: 3.0
PSRemotingProtocolVersion: 2.3
SerializationVersion: 1.1.0.1
**********************
**********************
Command start time: 20171030223255
**********************
PS C:\Users\Administrator> echo test
test
**********************
Command start time: 20171030223256
**********************
PS C:\Users\Administrator> exit
**********************
Windows PowerShell transcript end
End time: 20171030223256
**********************

System-wide transcription can be enabled through Group Policy as follows.

Warning
If system-wide transcription to a shared location is enabled, access to that directory should be limited to prevent users from viewing the transcripts of other users or computers.
  1. Open the Group Policy MMC snapin (gpedit.msc).

  2. Go to Computer Configuration  Administrative Templates  Windows Components  Windows PowerShell and open the Turn on PowerShell Transcription setting.

  3. Select Enabled. Set a system-wide transcript output directory if required. Check the Include invocation headers option (this setting generates a timestamp for each command and is recommended).

    Configuring the Transcription policy
Example 424. Parsing PowerShell Transcriptions

This configuration reads and parses transcript files written to the TRANSCRIPTS_DIR directory (which should be set appropriately). Headers, footers, and commands are parsed as separate events. $File and $EventTime fields are set for each event (invocation headers must be enabled for command timestamps). $Command and $Output fields are added for command events. Fields from the header entries are parsed with xm_kvp and added to the event record. Finally, the logs are converted to JSON format and forwarded via TCP.

Note
The HeaderLine below must be changed if invocation headers are not enabled. See the comment in the configuration.
nxlog.conf [Download file]
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
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
define TRANSCRIPTS_DIR C:\powershell

<Extension transcript_parser>
    Module      xm_multiline
    # Use this if invocation headers are ON (recommended)
    HeaderLine  /^\*{22}$/
    # Use this if invocation headers are OFF (not recommended)
    #HeaderLine  /^(\*{22}$|PS[^>]*>)/
    <Exec>
        $raw_event =~ s/^\xEF\xBB\xBF//;
        if get_var('include_next_record') and $raw_event =~ /^\*{22}$/
        {
            set_var('include_next_record', FALSE);
            $raw_event =~ s/^\*//;
        }
        else if $raw_event =~ /^Command start time: \d{14}$/
            set_var('include_next_record', TRUE);
    </Exec>
</Extension>

<Extension transcript_header_parser>
    Module          xm_kvp
    KVPDelimiter    \n
</Extension>

<Input transcription>
    Module      im_file
    File        '%TRANSCRIPTS_DIR%\\*PowerShell_transcript.*'
    InputType   transcript_parser
    <Exec>
        # Add file name as field to event record
        $File = file_name();

        # Drop extra separator line events
        if $raw_event =~ /^\*{22}$/
            drop();

        # Parse header and footer entries
        else if $raw_event =~ /(?x)^\*{22}\r\n
            (?<Message>Windows\ PowerShell\ transcript\ (start|end)\r\n
            (?<KVP>.*))$/s
        {
            $KVP =~ s/\r//g;
            transcript_header_parser->parse_kvp($KVP);
            delete($KVP);
            if ${Start time}
                $EventTime = strptime(${Start time}, '%Y%m%d%H%M%S');
            else
                $EventTime = strptime(${End time}, '%Y%m%d%H%M%S');
        }

        # Parse command entries with invocation headers
        else if $raw_event =~ /(?x)^\*{22}\r\n
            (?<Part1>Command\ start\ time:\ (?<EventTime>\d{14})\r\n)
            (?<Part2>\*{21}\r\nPS[^>]*>\ ?
                     (?<Command>[^\r\n]+)(\r\n(?<Output>.+))?)$/s
        {
            $Message = $Part1 + '*' + $Part2;
            delete($Part1);
            delete($Part2);
            $EventTime = strptime($EventTime, '%Y%m%d%H%M%S');
        }

        # Parse command entries without invocation headers
        else if $raw_event =~ /(?x)^PS[^>]*>\ ?
             (?<Command>[^\r\n]+)(\r\n(?<Output>.+))?$/s
            $Message = $raw_event;
        else log_warning('Failed to parse transcript entry');
    </Exec>
</Input>

The following output shows the first two events of the log sample above.

Output Sample
{
  "EventReceivedTime": "2017-10-30 22:32:49",
  "SourceModuleName": "transcription",
  "SourceModuleType": "im_file",
  "File": "C:\\powershell\\\\20171030\\PowerShell_transcript.WIN-FT17VBNL4B2.LcxuCZbr.20171030223248.txt",
  "Message": "Windows PowerShell transcript start\r\nStart time: 20171030223248\r\nUsername: WIN-FT17VBNL4B2\\Administrator\r\nRunAs User: WIN-FT17VBNL4B2\\Administrator\r\nMachine: WIN-FT17VBNL4B2 (Microsoft Windows NT 10.0.14393.0)\r\nHost Application: C:\\Windows\\system32\\WindowsPowerShell\\v1.0\\PowerShell.exe\r\nProcess ID: 4268\r\nPSVersion: 5.1.14393.1770\r\nPSEdition: Desktop\r\nPSCompatibleVersions: 1.0, 2.0, 3.0, 4.0, 5.0, 5.1.14393.1770\r\nBuildVersion: 10.0.14393.1770\r\nCLRVersion: 4.0.30319.42000\r\nWSManStackVersion: 3.0\r\nPSRemotingProtocolVersion: 2.3\r\nSerializationVersion: 1.1.0.1",
  "Start time": "20171030223248",
  "Username": "WIN-FT17VBNL4B2\\Administrator",
  "RunAs User": "WIN-FT17VBNL4B2\\Administrator",
  "Machine": "WIN-FT17VBNL4B2 (Microsoft Windows NT 10.0.14393.0)",
  "Host Application": "C:\\Windows\\system32\\WindowsPowerShell\\v1.0\\PowerShell.exe",
  "Process ID": "4268",
  "PSVersion": "5.1.14393.1770",
  "PSEdition": "Desktop",
  "PSCompatibleVersions": "1.0, 2.0, 3.0, 4.0, 5.0, 5.1.14393.1770",
  "BuildVersion": "10.0.14393.1770",
  "CLRVersion": "4.0.30319.42000",
  "WSManStackVersion": "3.0",
  "PSRemotingProtocolVersion": "2.3",
  "SerializationVersion": "1.1.0.1",
  "EventTime": "2017-10-30 22:32:48"
}
{
  "EventReceivedTime": "2017-10-30 22:32:56",
  "SourceModuleName": "transcription",
  "SourceModuleType": "im_file",
  "File": "C:\\powershell\\\\20171030\\PowerShell_transcript.WIN-FT17VBNL4B2.LcxuCZbr.20171030223248.txt",
  "Command": "echo test",
  "EventTime": "2017-10-30 22:32:55",
  "Output": "test",
  "Message": "Command start time: 20171030223255\r\n**********************\r\nPS C:\\Users\\Administrator> echo test\r\ntest"
}