Parse-DNSDebugLogFile

Happy Friday, nerds.

This is just going to be a quick post wherein I paste in a Powershell script I wrote about a year ago that parses a Windows Server DNS debug log file, and converts the log file from flat boring hard-to-read text, into lovely Powershell object output.  This makes sorting, analyzing and data mining your DNS log files with Powershell a breeze.

It's not my best work, but I wanted to get it posted on here because I forgot about it until today, and I just remembered it when I wanted to parse a DNS log file, and I tried searching for it here and realized that I never posted it.

#Requires -Version 2
Function Parse-DNSDebugLogFile
{
<#
.SYNOPSIS
    This function reads a Windows Server DNS debug log file, and turns it from
    a big flat file of text, into a useful collection of objects, with each
    object in the collection representing one send or receive packet processed
    by the DNS server.
.DESCRIPTION
    This function reads a Windows Server DNS debug log file, and turns it from
    a big flat file of text, into a useful collection of objects, with each
    object in the collection representing one send or receive packet processed
    by the DNS server. This function takes two parameters - DNSLog and ErrorLog.
    Defaults are used if no parameters are supplied.
.NOTES
    Written by Ryan Ries, June 2013.
#>
    Param([Parameter(Mandatory=$True, Position=1)]
            [ValidateScript({Test-Path $_ -PathType Leaf})]
            [String]$DNSLog,
          [Parameter()]
            [String]$ErrorLog = "$Env:USERPROFILE\Desktop\Parse-DNSDebugLogFile.Errors.log")

    # This is the collection of DNS Query objects that this function will eventually return.
    $DNSQueriesCollection = @()
    # Try to read in the DNS debug log file. If error occurs, log error and return null.
    Try
    {
        [System.Array]$DNSLogFile = Get-Content $DNSLog -ReadCount 0 -ErrorAction Stop
        If($DNSLogFile.Count -LT 30)
        {
            Throw "File was empty."
        }
    }
    Catch
    {
        "$(Get-Date) - $($_.Exception.Message)" | Out-File $ErrorLog -Append
        Write-Verbose $_.Exception.Message
        Return
    }
    
    # Cut off the header of the DNS debug log file. It's about 30 lines long and we don't want it.
    $DNSLogFile = $DNSLogFile[30..($DNSLogFile.Count - 1)]
    # Create a temporary buffer for storing only lines that look valid.
    $Buffer = @()
    # Loop through log file. If the line is not blank and it contains what looks like a numerical date,
    # then we can be reasonably sure that it's a valid log file line. If the line is valid,
    # then add it to the buffer.    
    Foreach($_ In $DNSLogFile)
    {
        If($_.Length -GT 0 -AND $_ -Match "\d+/\d+/")
        {
            $Buffer += $_
        }
    }
    # Dump the buffer back into the DNSLogFile variable, and clear the buffer.
    $DNSLogFile = $Buffer
    $Buffer     = $Null
    # Now we parse text and use it to assemble a Query object. If all goes well,
    # then we add the Query object to the Query object collection. This is nasty-looking
    # stuff that we have to do to turn a flat text file into a beutiful collection of
    # objects with members.
    Foreach($_ In $DNSLogFile)
    {
        If($_.Contains(" PACKET "))
        {
            $Query = New-Object System.Object
            $Query | Add-Member -Type NoteProperty -Name Date      -Value $_.Split(' ')[0]
            $Query | Add-Member -Type NoteProperty -Name Time      -Value $_.Split(' ')[1]
            $Query | Add-Member -Type NoteProperty -Name AMPM      -Value $_.Split(' ')[2]
            $Query | Add-Member -Type NoteProperty -Name ThreadID  -Value $_.Split(' ')[3]
            $Query | Add-Member -Type NoteProperty -Name PacketID  -Value $_.Split(' ')[6]
            $Query | Add-Member -Type NoteProperty -Name Protocol  -Value $_.Split(' ')[7]
            $Query | Add-Member -Type NoteProperty -Name Direction -Value $_.Split(' ')[8]
            $Query | Add-Member -Type NoteProperty -Name RemoteIP  -Value $_.Split(' ')[9]
            $BracketLeft  = $_.Split('[')[0]
            $BracketRight = $_.Split('[')[1]
            $Query | Add-Member -Type NoteProperty -Name XID       -Value $BracketLeft.Substring($BracketLeft.Length - 9, 4)
            If($BracketLeft.Substring($BracketLeft.Length - 4, 1) -EQ "R")
            {
                $Query | Add-Member -Type NoteProperty -Name Response -Value $True
            }
            Else
            {
                $Query | Add-Member -Type NoteProperty -Name Response -Value $False
            }
            $Query | Add-Member -Type NoteProperty -Name OpCode -Value $BracketLeft.Substring($BracketLeft.Length - 2, 1)
            $Query | Add-Member -Type NoteProperty -Name ResponseCode -Value $BracketRight.SubString(10, 8).Trim()
            $Query | Add-Member -Type NoteProperty -Name QuestionType -Value $_.Split(']')[1].Substring(1,5).Trim()
            $Query | Add-Member -Type NoteProperty -Name QuestionName -Value $_.Split(' ')[-1]
            
            # Just doing some more sanity checks here to make sure we parsed all that text correctly.
            # If something looks wrong, we'll just discard this whole line and continue on
            # with the next line in the log file.
            If($Query.QuestionName.Length -LT 1)
            {
                Continue
            }
            If($Query.XID.Length -NE 4)
            {
                "$(Get-Date) - XID Parse Error. The line was: $_" | Out-File $ErrorLog -Append
                Continue
            }
            If($Query.Protocol.ToUpper() -NE "UDP" -AND $Query.Protocol.ToUpper() -NE "TCP")
            {
                "$(Get-Date) - Protocol Parse Error. The line was: $_" | Out-File $ErrorLog -Append
                Continue
            }
            If($Query.Direction.ToUpper() -NE "SND" -AND $Query.Direction.ToUpper() -NE "RCV")
            {
                "$(Get-Date) - Direction Parse Error. The line was: $_" | Out-File $ErrorLog -Append
                Continue
            }
            If($Query.QuestionName.Length -LT 1)
            {
                Continue
            }
            
            # Let's change the query format back from RFC 1035 section 4.1.2 style, to the 
            # dot notation that we're used to. (8)computer(6)domain(3)com(0) = computer.domain.com.
            $Query.QuestionName = $($Query.QuestionName -Replace "\(\d*\)", ".").TrimStart('.')
            
            # Finally let's add one more property to the object; it might come in handy:
            $Query | Add-Member -Type NoteProperty -Name HostName -Value $Query.QuestionName.Split('.')[0].ToLower()
            
            # The line, which we've now converted to a query object, looks good, so let's
            # add it to the query objects collection.
            $DNSQueriesCollection += $Query
        }
    }
    $DNSLogFile = $Null
    
    # Clear the error log if it's too big.
    If(Test-Path $ErrorLog)
    {
        If((Get-ChildItem $ErrorLog).Length -GT 1MB)
        {
            Clear-Content $ErrorLog
        }
    }
    
    Return $DNSQueriesCollection
}
# END FUNCTION Parse-DNSDebugLogFile

And the output looks like this:

Date         : 6/17/2013
Time         : 11:51:41
AMPM         : AM
ThreadID     : 19BC
PacketID     : 0000000010146F10
Protocol     : UDP
Direction    : Snd
RemoteIP     : 10.173.16.82
XID          : e230
Response     : True
OpCode       : Q
ResponseCode : NOERROR
QuestionType : A
QuestionName : host01.domain.com.
HostName     : host01

Date         : 6/17/2013
Time         : 11:51:41
AMPM         : AM
ThreadID     : 19BC
PacketID     : 000000000811A6C0
Protocol     : UDP
Direction    : Snd
RemoteIP     : 10.173.16.82
XID          : 36df
Response     : True
OpCode       : Q
ResponseCode : NXDOMAIN
QuestionType : SRV
QuestionName : _kerberos-master._udp.domain.com.
HostName     : _kerberos-master

TechEd 2014

I have been wanting to attend TechEd for several years now, and finally I've attended my first one this year in Houston, Texas. Overall it was a great experience, although I was a little overwhelmed by having so much that I wanted to see and do and not enough time to do it all. I also feel disappointed that there was an emergency back home while I was at TechEd so I had to cut the trip short and miss an entire day of the conference. But, it's not the end of the world. I hope to be able to go back for TechEd 2015 next year.

Here are a few of my thoughts.

TechEd 2014 George R Brown Convention Center

I drove to Houston from Dallas, and arrived here at the George R Brown convention center on about 1 hour of sleep. Luckily I signed up as soon as registration opened, which meant that I was able to book a hotel room in the Hilton right across the street. All I had to do to get back and forth from my room to the convention center was cross the catwalk.


Monday's Keynote

It was extremely crowded. This conference was not for the agoraphobic. In fact, the conference was so congested, and the convention center so poorly designed to handle such a large crowd, it made it difficult to even move around at times. Many of the sessions (especially the Russinovich sessions) filled up 30 minutes before they were scheduled to begin. This was the first year Microsoft consolidated the MMS and TechEd conferences though, which did not help.

The conference center was a gigantic cuboid structure with no thought given to traffic flow, restroom layout, etc.

Endless hallway of TechEd conferences

That being said, the content was still great. Tons of cutting-edge System Center, Powershell Desired State Configuration, Azure stuff, and lots of security talks. (AKA "Trustworthy Computing") Lots, and lots of security talks. I almost lost count of how many times I got to see the presenters try to scare us by showing us Mimikatz to dump lsass.exe private memory, or export "non-exportable" private keys. And all the rockstars were there too; the guys that are essentially celebrities to me because of the awesome stuff they've done while at Microsoft.

Some of the other great content I saw:

  • Virtual Machine Manager Network Virtualization, which neatly solves the overlapping IP address situation in a multi-tenant environment.
  • Freaking Azure Pack which allows you to essentially deploy your very own private Azure inside your own organization.
  • Aaron Margosis trying to convince us to go up to Mark Russinovich and say to him, "Mr. Cogswell, I'm a huge fan of your work..."
  • Jeffrey Snover muttering "god damnit" to himself over and over again under his breath while trying to show us how to change the color of error text in our Powershell console.
  • Getting to pitch my idea to one of the Windows client security guys about LogonUI.exe performing a hash check on utilman.exe before launching it from the Accessibility button.
  • Etc.

Just another shot of the huge crowd
Just another shot of the endless sea of people.

High-tech signs
And an example of the high-tech digital signage.


Me and Ed Wilson
Me and Ed Wilson, AKA Dr. Scripto


Me and Mathias, whom I met on ServerFault, after a night of exploring the Tech Expo, drinking beer, walking, talking about the pathetic state of healthcare in the United States, and eating at the Cheesecake Factory.

Speaking of tech expo, this year it was all about SSDs, flash memory, ridiculous amounts of RAM for all your SQL 2014 In-Memory OLTP processing, and 56 gigabit Infiniband RoCE setups:





I hope to see you again next year, TechEd...

SceCli Warning Event 1202, Domain Local Groups, and Alias_Object sAMAccountType, OH MY

I haven't posted in forever, so today it's time to get back to my roots by troubleshooting some good old-fashioned Active Directory problems. I saw this issue in the wild recently, so I thought I'd write about it while it was still fresh on my mind.

An admin came to me asking for help, and explained how one of his customers was experiencing warning events in the Application event log every 5 minutes on their domain controllers, but not their member servers, looking like this:


Warning 1202


Log Name:      Application
Source:        SceCli
Date:          5/1/2014 5:25:56 PM
Event ID:      1202
Task Category: None
Level:         Warning
Keywords:      Classic
User:          N/A
Computer:      DC01.CONTOSO.COM
Description:   Security policies were propagated with warning. 0x4b8 : An extended error has occurred.


A couple of things will let you know immediately that this problem has something to do with Group Policy. First, that the event is logged every 5 minutes on each domain controller, which just so happens to be the GPO refresh interval on DCs. Second, that the event source is SceCli, which loosely stands for Security Configuration Client-Side Extension. You'll also notice an accompanying Error ID 7016 in the GroupPolicy event log that gives you even less helpful information:


Error 7016 GroupPolicy


If you were to search for information about this event on the web, you'll no doubt find Microsoft's KB 324383: Troubleshooting SCECLI 1202 Events, and find that the article is almost completely irrelevant to this scenario, except for the little bit at the end that tells you how to enable Winlogon logging. We need to enable that logging on one of the DCs to get a better understanding of what's going on. To enable said logging:

  • Locate and then click the following registry subkey:
    • HKEY_LOCAL_MACHINE\Software\Microsoft\Windows NT\CurrentVersion\Winlogon\GPExtensions\{827D319E-6EAC-11D2-A4EA-00C04F79F83A}
  • Add or Edit the following registry value:
    • Value name: ExtensionDebugLevel
    • Data type: DWORD
    • Value data: 2

The log should begin filling up at %SYSTEMROOT%\Security\logs\winlogon.log right away. In that log, I found the underlying cause of the error:

----Configure Group Membership...
                Configure Domain Admins.
                Configure LABS\Domain Admins.
                                object already member of Administrators.
                Configure LABS\IT_Department_Admins.
                Aliases cannot be members of other groups.

                Group Membership configuration was completed with one or more errors.


So something in Group Policy is attempting to configure group membership on this computer (that happens to be a DC) and is encountering an error while doing so. There are only a couple things in Group Policy that are designed to configure group membership. Group Policy Preferences is one... Restricted Groups is another. Let's dig through the GPOs in this domain and see which one is manipulating group memberships:



A GPO linked at the domain level (which means it applies to all domain computers including DCs,) was using Restricted Groups to ensure that the listed security groups were members of the BUILTIN\Administrators group on every computer in the domain. This was working fine on member servers, but causing errors on DCs. There were also other security groups being added to the BUILTIN\Administrators group on member servers and domain controllers successfully. So what was different about the IT_Department_Admins group? Why was it the only group causing us an error? Let's examine the IT_Department_Admins security group:



Spot the difference? The IT_Department_Admins security group is a Domain Local group, while the other groups that were giving us no problems were Global security groups. To cut to the chase instead of droning on about the difference between DL and Global groups, one of the things you'll notice about a Domain Local group object in Active Directory is that it has a sAMAccountType of OBJECT_ALIAS. Page 103 of [MS-SAMR] has this to say about alias accounts:

An alias object refers to a database object whose objectClass attribute is group or derived from group, and whose groupType contains GROUP_TYPE_RESOURCE_GROUP.

Two domains are exposed from a given server: an account domain and a built-in domain; this fact is true for both DC and non-DC configurations. The account domain refers to the object with objectClass domainDNS. The built-in domain refers to the object with the objectClass builtinDomain.

The built-in domain has the characteristic that its objectSid value is invariant (S-1-5-32) through all deployments and only contains aliases. There is exactly one built-in domain for every account domain.

So to fix the issue, we simply converted the Domain Local group to a Global group and called it a day. The issue stems from the fact that domain controllers don't really have a local SAM the same way that standalone Windows machines and Windows domain members do. When you create a DC, the accounts that were part of the "BUILTIN" domain on the computer are removed from the local SAM and put into NTDS.dit and can be found in the Builtin Container using a tool like ADUC.  Accounts in the Builtin container in AD have ... you guessed it: Domain Local scope.