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...

To Scriptblock or Not to Scriptblock, That is the Question

I was doing some work with the Active Directory Powershell cmdlets recently.  Well, I work with them almost every day, but they still get me with their idiosyncrasies from time to time.

I needed to check some group memberships on various privileged groups within the directory.  I'll show you an abridged version of the code I started with to get the point across, the idea of which is that I iterate through a collection of groups (a string array) and perform some actions on each of the Active Directory groups in sequence:

Foreach($ADGroupName In [String[]]'Domain Admins',     `
                                  'Enterprise Admins', `
                                  'Administrators',    `
                                  'Account Operators', `
                                  'Backup Operators')
{
    $Group = Get-ADGroup -Filter { Name -EQ $ADGroupName } -Properties Members
    If ($Group -EQ $Null -OR $Group.PropertyNames -NotContains 'Members')
    {
        # This condition only occurs on the first iteration of the Foreach loop!
        Write-Error "$ADGroupName was null or was missing the Members property!"
    }
    Else
    {
        Write-Host "$ADGroupName contains $($Group.Members.Count) members." 
    }
}

Before I continue, I'd just like to mention that I typically do not mind very long lines of code nor do I avoid verbose variable names, mostly because I'm always using a widescreen monitor these days.  Long gone are the days of the 80-character-wide terminal.  And I agree with Don Jones that backticks (the Powershell escape character) are to be avoided on aesthetic grounds, but for sharing code in formats that are less conducive to long lines of code, such as this blog or a StackExchange site with their skinny content columns, I'll throw some backticks in to keep the horizontal scrolling to a minimum. 

Anyway, the above code exhibited the strangest bug. At least I'd call it a bug. (I'll make sure and let Jeffrey Snover know next time I see him. ;P) Only on the first iteration of the Foreach loop, I would get the "error" condition instead of the expected "Domain Admins contains 5 members" output.  The remaining iterations all behaved as expected.  It did not matter in what order I rearranged the list of AD groups; I always got an error on the first element in the array.

For a moment, I settled on working around the "bug" by making a "Dummy Group," including that as the first item in the array, gracefully handling the expected exception because Dummy Group did not exist, and then continuing normally with the rest of the legitimate groups.  This worked fine, but it didn't sit well with me.  Not exactly my idea of production-quality code.  I wanted to find the root cause of this strange behavior.

Stackoverflow has made me lazy.  Apparently I go to Serverfault when I want to answer questions, and Stackoverflow when I want other people to answer questions for me.  Simply changing line 7 above to this:

$Group = Get-ADGroup -Filter "Name -EQ '$ADGroupName'" -Properties Members

Made all the difference.  That is, using a string with an expandable variable inside it instead of the script block for a filter.  (Which itself is a little confusing since single quotes (') usually indicate non-expandable variables.  Oh well.  Just syntax to remember when playing with these cmdlets.

Nevertheless, if the code would not work correctly with a script block, I wish the parser would mark it as a syntax error, instead of acting weird.  (Behavior exists in PS 2 and PS 4, though in PS 4 the missing property is just ignored and I get 0 members, which is even worse.)

Powershell, Panchromatic Edition, Continued!

That is a weird title.  Anyway, this post is a continuation to my last post, here, in which I used Powershell to create a bitmap that contained each and every RGB color (24-bit, ~16.7 million colors) exactly once.  We learned that using dynamic arrays and the += operator are often not a good choice when working with large amounts of data that you'd like to see processed before your grandchildren graduate high school. Today we look at another performance pitfall.

So last time, I printed a 4096x4096 bitmap containing 16777216 colors. But the pixels were printed out in a very uniform, boring manner.  I wanted to at least see if I could randomize the pixels a little bit to make the image more interesting.  First, I attempted to do that like this:

Function Shuffle([System.Collections.ObjectModel.Collection[System.Drawing.Color]]$List)
{
    $NewList = New-Object 'System.Collections.ObjectModel.Collection[System.Drawing.Color]'
    While ($List.Count -GT 0)
    {
        [Int]$RandomIndex = Get-Random -Minimum 0 -Maximum $List.Count                
        $NewList.Add($List[$RandomIndex])
        $List.RemoveAt($RandomIndex)
        Write-Progress -Activity "Randomizing Pixels..." -Status "$($NewList.Count) of 16777216"
    }
    Return $NewList
}

Seems pretty solid, right?  I intend to shuffle or randomize the neatly ordered list of pixels that I've generated.  So I pass that neatly ordered list to a Shuffle function.  The Shuffle function randomly plucks an element out of the original list one at a time, inserts it into a new "shuffled" list, then removes the original element from the old list so that it is not reused. Finally, it returns the new shuffled list.

Yeah... so that runs at about 12 pixels per second.

So instead of waiting 16 days for that complete, (16.7 million elements at 12 per second...)  I decided that I had to come up with a better solution.  I thought on it, and I almost resorted to writing a pure C# type and adding that to my script using Add-Type, but then I decided that would be "cheating" since I wanted to write this in Powershell as best I could.

Then it suddenly hit me: maybe I was thinking about it this way too hard.  Let's try something crazy:

Write-Progress -Activity "Randomizing Pixels" -Status "Please wait..."
$RandomPixelList = $AllRGBCombinations | Get-Random -Count $AllRGBCombinations.Count

Done in about two minutes, which beats the hell out of 16 days.  What we have now is a "randomized" list of pixels. Let's paint them and see how it looks:

A slice at 1x magnification:

A slice at 6x magnification:

I call it the "Cosmic Microwave Background."

You'll likely see a third installment in this series as I work some interesting algorithm into the mix so that the image is more interesting than just a random spray of pixels.  Until then...

Powershell Dynamic Arrays Will Murder You, Also... A Pretty Picture! (Part 1 of X)

I was browsing the web a couple days ago and I saw this post, which I thought was a fun idea.  I didn't want to look at his code though, because, kind of like reading movie spoilers, I wanted to see if I could do something similar myself first before spoiling the fun of figuring it out on my own. The idea is that you create an image that contains every RGB color, using each color only once.

Plus I decided that I wanted to do it in Powershell, because I'm a masochist.

There are 256 x 256 x 256 RGB colors (in a 24-bit spectrum.) That equals 16777216 colors. Since each color will be used only once, if I only use 1 pixel per color, a 4096 x 4096 image would be capable of containing exactly 16777216 different colors.

First I thought to just generate a random color, draw the pixel in that color, then add it to a list of "already used" colors, and then on the next iteration, just keep generating random colors in a loop until I happen upon one that wasn't in my list of already used colors. But I quickly realized this would be horribly inefficient and slow.  Imagine: to generate that last pixel, I'd be running through the loop all day hoping for the 1 in ~16.7 million chance that I got the last remaining color that hadn't already been used. Awful idea.

So instead let's just generate a big fat non-random array of all 16777216 RGB colors:

#
$AllRGBCombinations = @()
For ([Int]$Red = 0; $Red -LT 256; $Red++)
{
    For ([Int]$Green = 0; $Green -LT 256; $Green++)
    {
        For ([Int]$Blue = 0; $Blue -LT 256; $Blue++)
        {
            $AllRGBCombinations += [System.Drawing.Color]::FromArgb($Red, $Green, $Blue)
        }
    }
}

That does generate an array of 16777216 differently-colored and neatly-ordered pixel objects... but guess how long it takes?

*... the following day...*

Well, I wish I could tell you, but I killed the script after it ran for about 20 hours. I put a progress bar in just to check that it wasn't hung or in an endless loop, and it wasn't... the code is just really that slow.  It starts out at a decent pace and then gradually slows to a crawl.

Ugh, those dynamic arrays and the += operator strike again. I suspect it's because the above method recreates and resizes the array every iteration... like good ole' ReDim back in the VBscript days.  It may be handy for small bits of data, but if you're dealing with large amounts of data, that you want processed this decade, you better strongly type your stuff and use lists.  Let's try the above code another way:

#
$AllRGBCombinations = New-Object 'System.Collections.ObjectModel.Collection[System.Drawing.Color]'
For ([Int]$Red = 0; $Red -LT 256; $Red++)
{
    For ([Int]$Green = 0; $Green -LT 256; $Green++)
    {        
        For ([Int]$Blue = 0; $Blue -LT 256; $Blue++)
        {
            $AllRGBCombinations.Add([System.Drawing.Color]::FromArgb($Red, $Green, $Blue))
        }
    }
    $PixelsGenerated += 65536
    Write-Progress -Activity "Generating Pixels..." -Status "$PixelsGenerated / 16777216" -PercentComplete (($PixelsGenerated / 16777216) * 100)
}

Only 5.2 seconds in comparison, including the added overhead of writing the progress bar. Notice how I only update the progress bar once every 256 * 256 pixels, because it will slow you down a lot if you try to update the progress bar after every single pixel is created.

Now I can go ahead and generate an image containing exactly one of every color that looks like this:

Yep, there really are 16.7 million different colors in there, which is why even a shrunken PNG of it is 384KB.  Hard to compress an image when there are NO identical colors! The original 4096x4096 bitmap is ~36MB.  And I ended up loading a shrunken and compressed JPG for this blog post, because I didn't want every page hit consuming a meg of bandwidth.

It kinda' makes you think about how limited and narrow a human's vision is, doesn't it?  24-bit color seems to be fine for us when watching movies or playing video games, but that image doesn't seem to capture how impressive our breadth of vision should be.

Next time, we try to randomize our set of pixels a little, and try to make a prettier, less computerized-looking picture... but still only using each color only once.  See you soon.