Wednesday, September 28, 2016

NxLog For the Win

About a year ago Brian Wilson and myself talked about ELK at Raleigh InfoSeCon. As many of you know, ELK (ElasticSearch/Logstash/Kibana) is a wonderful solution for log management and it's completely free if you know what you are doing. If you are interested, that presentation can be found here. It's a little outdated due to the new versions of the software but still gives a good high level overview of the infrastructure. During the presentation we also briefly looked at NxLog as a log forwarder for our Windows environment.

Over the past few months, we've had the need to start pulling additional Window Event logs and formatting them for ingest of other products. While this seems fairly straight forward, it posed quite a few problems due to our infrastructure having multiple domains across the world and the fact that Windows event logs suck.

So let's start out by looking at a fairly basic NxLog config and what all it does.

<Extension _syslog>
    Module      xm_syslog
</Extension>
<Input in>
    Module       im_msvistalog
    ReadFromLast True
    Query <QueryList>\
      <Query Id="0">\
<Select Path="Security">*[System[(EventID='4624')]]</Select>\
<Select Path="Security">*[System[(EventID='4625')]]</Select>\
<Select Path="Security">*[System[(EventID='4648')]]</Select>\
<Select Path="Security">*[System[(EventID='4740')]]</Select>\
<Select Path="Security">*[System[(EventID='4768')]]</Select>\
    </QueryList>
    Exec to_syslog_bsd();
    Exec if $raw_event =~ /Account Name:\s+\S+\$\s+Account Domain:/ drop(); \
         else if $raw_event =~ /^(.+)(Detailed Authentication Information:|Additional Information:)/ $raw_event = $1; if $raw_event =~ s/\t/  /g {}    
</Input>
<Output out>
    Module        om_udp
    Host   X.X.X.X
    Port YYY
</Output>
<Route 1>
    Path        in => out
</Route>
The first section is fairly straight forward on calling the module xm_syslog since that is how we are sending the logs to our syslog cluster. The "Input in" section is where we start our modifications. At a high level, this section determines what logs NxLog will pay attention to. There are multiple ways to do this but I felt that listening out the event IDs per line made it very easy to read and we can quickly add/remove IDs if needed.

Once we pull all of the events we are interested in, we get to the real benefit of NxLog, being able to modify logs before sending them out. The first Exec statement is just converting the Windows format to syslog format since that is what I'm more comfortable and familiar with. After that, we have 2 if statements that provide additional filtering.

The first if statement looks to see if the Account Name has a $ in it. When reviewing the raw logs from our Domain Controllers, we saw a lot of computer logins which were out of scope for our project. Since none of our usernames has a $ in it, we simply drop them from the start.

The next statement then looks at the raw event, the one line syslog formatted Windows event, and says capture everything before "Detailed Authentication Information" or "Additional Information" and store that as a variable. From there, take that variable and make it the new $raw_event and then if there are any tabs in it, replace it with spaces.

So for anyone who is not familiar with how ugly and cumbersome Windows event logs can be, these few minor changes make a world of difference. The log then goes from this:
Sep 28 12:34:02 server.domain.com Microsoft-Windows-Security-Auditing[572]: An account was successfully logged on.    Subject:   Security ID: S-2-5-14   Account Name: SERVERDC1$   Account Domain: EXNETTST   Logon ID: 0x3f8    Logon Type: 10    New Logon:   Security ID: S-1-5-21-1092342493-3311231447-1094723392-1211   Account Name: user1   Account Domain: EXNETTST   Logon ID: 0x123331bc9   Logon GUID: {36616666-71C5-66A9-222-AB4540DG1FD6}    Process Information:   Process ID: 0xdee0   Process Name: C:\Windows\System32\winlogon.exe    Network Information:   Workstation Name: SERVERDC1   Source Network Address: 192.168.1.3   Source Port: 7255    Detailed Authentication Information:   Logon Process: User32   Authentication Package: Negotiate   Transited Services: -   Package Name (NTLM only): -   Key Length: 0    This event is generated when a logon session is created. It is generated on the computer that was accessed.    The subject fields indicate the account on the local system which requested the logon. This is most commonly a service such as the Server service, or a local process such as Winlogon.exe or Services.exe.    The logon type field indicates the kind of logon that occurred. The most common types are 2 (interactive) and 3 (network).    The New Logon fields indicate the account for whom the new logon was created, i.e. the account that was logged on.    The network fields indicate where a remote logon request originated. Workstation name is not always available and may be left blank in some cases.    The authentication information fields provide detailed information about this specific logon request.   - Logon GUID is a unique identifier that can be used to correlate this event with a KDC event.   - Transited services indicate which intermediate services have participated in this logon request.   - Package name indicates which sub-protocol was used among the NTLM protocols.   - Key length indicates the length of the generated session key. This will be 0 if no session key was requested.
To this:
Sep 28 12:39:00 server.domain.com Microsoft-Windows-Security-Auditing[572]: An account was successfully logged on.    Subject:    Security ID:    S-1-1-0    Account Name:    -    Account Domain:    -    Logon ID:    0x0    Logon Type:      3    Impersonation Level:    Impersonation    New Logon:    Security ID:    S-1-5-21-1843002-1947066824-37174299-191115    Account Name:    user1    Account Domain:    DOMAINNAME    Logon ID:    0x403432AC2    Logon GUID:    {14446E51-C7F8-B344-E16F-7A8DF1C2D33}    Process Information:    Process ID:    0x0    Process Name:    -    Network Information:    Workstation Name:      Source Network Address:  192.168.1.3    Source Port:    51223
While that makes a huge difference, there is room for improvement. One particular area of trouble we ran into was that Kerberos events and Windows Event ID 4624 logon events were quite a bit different. If you are relying on an application on the back end that doesn't support multiple regex filters or expects a uniform format from all logs, it poses a problem.

So back to the nxlog.conf file we go. Our new Exec commands would look like this:

    Exec to_syslog_bsd();
    Exec if $raw_event =~ /Account Name:\s+\S+\$\s+Account Domain:/ drop(); \
         else if ($EventID == 4624 or $EventID == 4768) $raw_event = "Time:" + $EventTime + ", EventID:" + $EventID + ", LogonType:" + $LogonType + ", User:" + $TargetDomainName + "\\" + $TargetUserName + ", IPAddr:" + $IPAddress; \
   else if $raw_event =~ /^(.+)(Detailed Authentication Information:|Additional Information:)/ $raw_event = $1; if $raw_event =~ s/\t/  /g {}
We start out the same but our second if statement has a sub-filter in it. If the Event ID matches 4624 or 4768, then do some additional parsing. By default, NxLog is aware of certain fields and stores them as variables. You can look up the full list on the NxLog man page but the fields above are the ones we were interested in. After that parsing, it then goes back to our previous regex for any other ID that comes through. Below is an example of a 4624 and 4768 event.
Sep 28 00:14:20 server.domain.com Time:2016-09-28 00:14:20, EventID:4624, LogonType:3, User:DOMAIN\user1, IPAddr:192.168.1.66
Sep 28 00:14:21 server.domain.com Time:2016-09-28 00:14:20, EventID:4768, LogonType:, User:DOMAIN.COM\user2, IPAddr:::ffff:192.168.5.2
As you can see, we now have a very clean format that the end device can parse out. There is more room for improvement to get rid of the :::ffff: in the Kerberos events but we were able to parse them out on the back end.

So overall, NxLog is amazing. It allows you to take the load off of your central syslog cluster and distribute it across all of your endpoints that are generating logs. This also decreases the amount and size of events coming into your cluster from the start so you are only getting exactly the items that you need.

Hopefully this will help someone out in the same situation. Please let me know if you have any questions/comments.

No comments:

Post a Comment

Rogers Pass Trail (Heart Lake)

Drive & Parking This hike is close to Winter Park, CO but you don't take the normal Winter Park route over the pass. We went west o...