joeware - never stop exploring... :)

So you will recall my previous post on AdFind and PowerShell using S.DS.Protocols…

If you read activedir.org you will know that I realized some odd things occurred… I didn’t want to post back here until I had some more understanding of what is going on but now almost 2 weeks later I still haven’t a clue what is going on. I wanted to respond though. Admittedly the weather has been pretty nice here lately so I haven’t been playing computer geek as much as I did on the 9th when we had tornadoes whistling around the area (don’t worry, closest that got to me was about 3 miles away, so plenty of safety margin).

Basically the problem is that I have one PowerShell window that is performing like complete crap for the test script, and other Windows I open even though I seem to configure them similarly perform fine normally. I have been able to cause them to slow down a little by running the same commands over and over and watching it suck up silly amounts of memory but haven’t gotten it to slow down to the point the first window slows down. This really bothers me, I hate inconsistency. It throws all sorts of doubt on testing and what you have in front of you.

Interestingly running AdFind out of the two PowerShell windows results in identical performance, it is entirely within the realm of the PoS Scripts and .NET. But what? ~Eric suggested using some CLR profiler application but it apparently can’t profile something that is already running, you have to launch it with the profiler and unfortunately, my screwed up PoS window is already running.

Looking at the two Windows now, the PoS window that is “acting up” in which I just reran the test script to make sure it is still screwing up and that is all it has done in a couple of days is sitting there sucking up 140MB of RAM. The other PoS window is is using a “paltry”[1] 14MB[2].

When running in these “other” windows, the performance of PowerShell with the script is within 25% of AdFind. This is much closer to what I was expecting when I first tested it. The processor utilization of the “good” window is considerably less than what I saw with the “bad” window. Better actually than I expected out of PoS which is good. Network utilization is also much closer to AdFind which is what I expected; its the same data coming over the wire.

Again, I have no clue why that one PoS window is being troublesome, sorry. No answers here for you on that.

So anyway, oddness aside, I wanted to comment on each of the points from before.

1. Testing Methodology

I didn’t like Brandon’s testing methodology, I still don’t like what he initially did. He changed it and is now posting numbers with the new methodology. Very nice. 🙂

2. Testing Environment

Nothing new here.

3. Considerable performance hit on the machine running the tools…

This is related to the “bad” PoS window. Again, no clue what is happening here. The “good” PoS window has much better performance characteristics.

4. Network utilization

As mentioned above, this is now in line with AdFind as originally anticipated, again this was screwed before due to the bad window.

5. Umm there is a problem in the PoS Script…

This was all me, shortly afterward I realized while chatting with Dean about it that I used objectclass=* for AdFind and PoS was only doing an objectclass=user. I told Dean, I assume he passed that info on to Brandon.

6. The PoS doesn’t seem to fast in relation to AdFind…

Again, this is related to the bad window. The results are much closer now; within 25% in my limited tests.

 

While I have been off doing whatever, Brandon has continued forward in his tests, I highly recommend checking his blog out and reading about them. You can find it here – http://bsonposh.com/. He actually has some stuff way cooler than the perf testing that he has posted about now which is the STATS control stuff. He has sample code on how to return that info which I highly applaud. I know he spent a good portion of the weekend working through it as I got a bunch of emails from him on the details etc of it. I helped with what I felt I could[4] and then he found some docs up on MSFT in the protocols descriptions that were recently posted for legal reasons that actually describe all the stuff I had to reverse back in 2004 – http://msdn.microsoft.com/en-us/library/cc200562.aspx. I didn’t look closely at the code, but note that there were some changes in the STATS handling around the 2003 SP1 time frame as I had several people hit me with bug reports and I had to change how I was handling some of the info. I think the issue was around the calltime stuff but it was back in 2005 and I honestly don’t recall the details at the moment.

Oh Brandon mentions on his blog how PoS started surpassing AdFind for most tests when he started doing CSV data and that I would explain why. I explained to Brandon (and Dean) prior to them even getting into the tests that I expected it to occur. I don’t care too much to get into it but the gist is that the CSV handling was a hack into the tool to try and get it in there (along with -soao and -oao switches) because so many people were asking for it and I previously wasn’t planning on doing it until I built the 2.0 version of the AdFind internal logic framework[5]. Anyway when I say hack, I mean total hack, I am passing whole AdFind formatted output strings for the entire object around internally like for example

dn:DC=test,DC=loc
>objectClass: top
>objectClass: joeware-ServerClass
>objectClass: domain
>objectClass: domainDNS
>description: Test.Loc
>distinguishedName: DC=test,DC=loc
>instanceType: 5
>whenCreated: 20060512031950.0Z
>whenChanged: 20080529025642.0Z
>subRefs: CN=Configuration,DC=test,DC=loc
>subRefs: DC=ForestDnsZones,DC=test,DC=loc
>subRefs: DC=DomainDnsZones,DC=test,DC=loc
>uSNCreated: 7254

<SNIP>

and then reparsing them and reformatting into CSV format, etc. It seriously is a mess. The issue is lots of string passing between functions etc which means lots of string class instantiation going on which is dramatically slowing the AdFind down. When I was testing it back then I was seeing differences in speed between 20-60%, it was literally enough of a delta to see the difference in the output to the console. That almost prevented me from releasing the -csv/-soao/-oao switches at all. Then just bit the bullet because of my plans to rewrite the whole thing anyway. The ideas behind the new engine for AdFind will be to not do any of the formatting of the output until the very end and then it will go through a custom class that will figure out where that output is going – pipe, redirection, file, etc and output the info appropriately which should handle some of the various unicode issues people encounter at the command prompt[6].

In summary, the PoS stuff is running pretty well, when you don’t have a bad PoS Window. How you would detect that I don’t know, just have an idea on how fast your script should run I guess. For doing ad hoc DS stuff, would totally say this is fine, for constant running apps that use the directory, still won’t recommend .NET let alone PoS. PoS (and .NET) still has a lot of overhead (I had a window running some tests the other day that was eating 1.5GB and would have taken more but there was no more to take so it started throwing System.OutOfMemoryException errors…) and has been a wee bit unstable for me[7].

Possibly more later.

Oh one last thing, I tried to tweak one of Brandon’s scripts and obviously did it wrong, but it is fun to see how PoS handles it… I am currently at 1.25GB RAM being sucked up and 50%+ utilization on the PoS shell trying to run it…

$SearcherExpression = @’
$searcher = new-object System.DirectoryServices.DirectorySearcher([ADSI]””,”(objectclass=user)”,@(“distinguishedName”))
$searcher.pagesize = 1000
$searcher.findall()
‘@
Write-Host “Test 1”
Write-Host (“-“*40)
$myresults1 = “” | select @{n=”DirectorySearcher 1″;e={(Measure-command {invoke-expression $SearcherExpression}).TotalSeconds}},
                          @{n=”DirectorySearcher 2″;e={(Measure-command {invoke-expression $SearcherExpression}).TotalSeconds}},
                          @{n=”DirectorySearcher 3″;e={(Measure-command {invoke-expression $SearcherExpression}).TotalSeconds}},
                          @{n=”DirectorySearcher 4″;e={(Measure-command {invoke-expression $SearcherExpression}).TotalSeconds}},
                          @{n=”DirectorySearcher 5″;e={(Measure-command {invoke-expression $SearcherExpression}).TotalSeconds}}, 
                          @{n=”ADFind 1″;e={(Measure-Command { .\adfind -b “dc=test,dc=loc” -c -f “(objectclass=user)” }).TotalSeconds}},
                          @{n=”ADFind 2″;e={(Measure-Command { .\adfind -b “dc=test,dc=loc” -c -f “(objectclass=user)” }).TotalSeconds}},
                          @{n=”ADFind 3″;e={(Measure-Command { .\adfind -b “dc=test,dc=loc” -c -f “(objectclass=user)” }).TotalSeconds}},
                          @{n=”ADFind 4″;e={(Measure-Command { .\adfind -b “dc=test,dc=loc” -c -f “(objectclass=user)” }).TotalSeconds}},
                          @{n=”ADFind 5″;e={(Measure-Command { .\adfind -b “dc=test,dc=loc” -c -f “(objectclass=user)” }).TotalSeconds}},
                          @{n=”DSP Using 1.1 1″;e={(Measure-command { .\Test-DSProtocalsSP.ps1 }).TotalSeconds}}
                          @{n=”DSP Using 1.1 2″;e={(Measure-command { .\Test-DSProtocalsSP.ps1 }).TotalSeconds}}
                          @{n=”DSP Using 1.1 3″;e={(Measure-command { .\Test-DSProtocalsSP.ps1 }).TotalSeconds}}
                          @{n=”DSP Using 1.1 4″;e={(Measure-command { .\Test-DSProtocalsSP.ps1 }).TotalSeconds}}
                          @{n=”DSP Using 1.1 5″;e={(Measure-command { .\Test-DSProtocalsSP.ps1 }).TotalSeconds}}
$myresults1 | fl
Write-Host “Test 2”
Write-Host (“-“*40)
$myresults2 = “” | select @{n=”ADFind #1″;e={(Measure-Command { .\adfind -b “dc=test,dc=loc” -c -f “(objectclass=user)” }).TotalSeconds}},
                          @{n=”ADFind #2″;e={(Measure-Command { .\adfind -b “dc=test,dc=loc” -c -f “(objectclass=user)” }).TotalSeconds}},
                          @{n=”ADFind #3″;e={(Measure-Command { .\adfind -b “dc=test,dc=loc” -c -f “(objectclass=user)” }).TotalSeconds}},
                          @{n=”ADFind #4″;e={(Measure-Command { .\adfind -b “dc=test,dc=loc” -c -f “(objectclass=user)” }).TotalSeconds}},
                          @{n=”ADFind #5″;e={(Measure-Command { .\adfind -b “dc=test,dc=loc” -c -f “(objectclass=user)” }).TotalSeconds}},
                          @{n=”DSP Using 1.1 #1″;e={(Measure-command { .\Test-DSProtocalsSP.ps1 }).TotalSeconds}}
                          @{n=”DSP Using 1.1 #2″;e={(Measure-command { .\Test-DSProtocalsSP.ps1 }).TotalSeconds}}
                          @{n=”DSP Using 1.1 #3″;e={(Measure-command { .\Test-DSProtocalsSP.ps1 }).TotalSeconds}}
                          @{n=”DSP Using 1.1 #4″;e={(Measure-command { .\Test-DSProtocalsSP.ps1 }).TotalSeconds}}
                          @{n=”DSP Using 1.1 #5″;e={(Measure-command { .\Test-DSProtocalsSP.ps1 }).TotalSeconds}}
                          @{n=”DirectorySearcher #1″;e={(Measure-command {invoke-expression $SearcherExpression}).TotalSeconds}},
                          @{n=”DirectorySearcher #2″;e={(Measure-command {invoke-expression $SearcherExpression}).TotalSeconds}},
                          @{n=”DirectorySearcher #3″;e={(Measure-command {invoke-expression $SearcherExpression}).TotalSeconds}},
                          @{n=”DirectorySearcher #4″;e={(Measure-command {invoke-expression $SearcherExpression}).TotalSeconds}},
                          @{n=”DirectorySearcher #5″;e={(Measure-command {invoke-expression $SearcherExpression}).TotalSeconds}}, 

$myresults2 | fl
Write-Host “Test 3”
Write-Host (“-“*40)
$myresults3 = “” | select @{n=”DSP Using 1.1 #1″;e={(Measure-command { .\Test-DSProtocalsSP.ps1 }).TotalSeconds}}
                          @{n=”DSP Using 1.1 #2″;e={(Measure-command { .\Test-DSProtocalsSP.ps1 }).TotalSeconds}}
                          @{n=”DSP Using 1.1 #3″;e={(Measure-command { .\Test-DSProtocalsSP.ps1 }).TotalSeconds}}
                          @{n=”DSP Using 1.1 #4″;e={(Measure-command { .\Test-DSProtocalsSP.ps1 }).TotalSeconds}}
                          @{n=”DSP Using 1.1 #5″;e={(Measure-command { .\Test-DSProtocalsSP.ps1 }).TotalSeconds}}
                          @{n=”DirectorySearcher #1″;e={(Measure-command {invoke-expression $SearcherExpression}).TotalSeconds}},
                          @{n=”DirectorySearcher #2″;e={(Measure-command {invoke-expression $SearcherExpression}).TotalSeconds}},
                          @{n=”DirectorySearcher #3″;e={(Measure-command {invoke-expression $SearcherExpression}).TotalSeconds}},
                          @{n=”DirectorySearcher #4″;e={(Measure-command {invoke-expression $SearcherExpression}).TotalSeconds}},
                          @{n=”DirectorySearcher #5″;e={(Measure-command {invoke-expression $SearcherExpression}).TotalSeconds}}, 
                          @{n=”ADFind #1″;e={(Measure-Command { .\adfind -b “dc=test,dc=loc” -c -f “(objectclass=user)” }).TotalSeconds}},
                          @{n=”ADFind #2″;e={(Measure-Command { .\adfind -b “dc=test,dc=loc” -c -f “(objectclass=user)” }).TotalSeconds}},
                          @{n=”ADFind #3″;e={(Measure-Command { .\adfind -b “dc=test,dc=loc” -c -f “(objectclass=user)” }).TotalSeconds}},
                          @{n=”ADFind #4″;e={(Measure-Command { .\adfind -b “dc=test,dc=loc” -c -f “(objectclass=user)” }).TotalSeconds}},
                          @{n=”ADFind #5″;e={(Measure-Command { .\adfind -b “dc=test,dc=loc” -c -f “(objectclass=user)” }).TotalSeconds}},

$myresults3 | fl
$myresults1,$myresults2,$myresults3

 

    joe

 

 

[1] Said in a sarcastic tone…. 😉

[2] For comparison, the five command prompt windows I have had open since the mid-May and that I do practically everything I do on the computer including hundreds if not thousands[3] of AdFind/AdMod commands are using 5MB combined. The PowerShell window I just opened to see how much memory it used on launch has 27MB.

[3] I run test commands against my various test AD domains all throughout the day for work.

[4]  I wasn’t about to talk about what I reverse engineered because I didn’t want to get in trouble for that…

[5] Good thing I didn’t wait, I still haven’t finished that one. 😉

[6] Not positive but last I heard, console .NET apps have the same issues. You can test it by putting in an object in your directory with some characters with umlauts or other fun characters and then write a console app to display them at the console them redirect them then pipe them and then write them to a file and then make sure it is displayed properly each way. Unicode is a bit of a pain.

[7] In trying to do various things to make it slow down like the first window I caused PoS to crash several times which I can’t recall ever doing to a command prompt window. I can understand if a script blows or an app blows, but I don’t think it should take out the shell window in the process.

So Brandon stepped up and did something I didn’t think anyone would step up and do… Start profiling and comparing the performance of PowerShell and .NET DS Protocols against a native App using the wldap32 LDAP library[1]. Brandon’s first blog entry on the topic is here – http://bsonposh.com/archives/325

While I am going to question Brandon’s testing a little here, especially his results, I commend him for taking the time and energy to step up and actually do this[3].

I guess I should state my underlying thoughts on this whole topic since some people know, some people don’t know, and a whole lot of people *think they know* what I think about it… I would be happy to see PoS+.NET compete with or even beat out a native app+wldap32, I don’t expect it, but I would be happy to see it[6]. I definitely don’t expect to see the numbers Brandon is showing on his blog which is why I am taking the time to look at this with the detail that I am going to provide.

Anyway… Historically, there is almost always a tradeoff in terms of speed and ease of use. For instance, C++ is easier to use than Assembler but if you have a great C++ programmer and a great ASM programmer, the ASM programmer will write more code but it should almost certainly be faster, smaller compiled footprint, and more efficient overall. However some things are so painful to do or take so long or require so much code that we have moved from using ASM to using C and then C++ and other higher level compiled languages[7]. This is one of the big reasons why you use .NET. It isn’t about performance of the running code, it is about how fast you can get to having running code. It is, IMO, sort of a RAD tool, not something you want to put into heavy use, but something to prototype out what you want to do or if you just need to do something quick.

 

So after running through the tests, my results are so radically different from Brandon’s I wonder what is going on. If someone sees a mistake in the testing I followed, please let me know. I expected the results to not be as good as what Brandon came up with but I didn’t expect them to be as bad as they were.

 

1. Testing Methodology.

I don’t really like how Brandon ran his tests from a couple of angles.

The first thing I don’t like is that he uses PoS to measure the speed of PoS and AdFind. I have no clue what overhead is in there which is why I don’t like it. Brandon is obviously comfortable with it however. Whether that is blind faith or he has done comprehensive tests to prove out that it is trustworthy, I don’t know… I do know that I can’t and won’t assume the latter. His trust in it does not transition to me. I am quite untrusting.

The second thing I don’t like is how the commands are all mixed up together. When I am measuring speed on commands, especially something for AD,  I tend to run the same command over and over again so that caching is taken out of the picture as well as anything else. What I am looking for out of the numbers is consistency in times to run the specific command. If you don’t see consistency, it tends to mean something else is playing into the tests. I would prefer to see 5, 10, or 100 runs of the same command in a row and then ditto for the next command and the next, etc. I don’t see consistency in Brandon’s reported numbers. Way too much skew.

 

Solutions

My solutions for these issues are

A. Instead of using a PoS script to launch AdFind and the Counting PoS script, I changed the prompt in PoS to include the current time with the following command

function prompt {Write-Host $(get-date).Tostring(“yyyy-MM-dd HH:mm:ss”)}

That gives me a prompt that looks like

2008-06-08 17:16:25
PS>

Then I just paste in my commands I want to run with a blank line at the beginning and end of the command sequence. This is something I do in the normal command prompt as well (though my prompt in that case is instead prompt=[$D $T] $M$+ $_$P$G). That makes it so the shell stamps the time to the console right there on the spot like so…

Command Sequence

• [ENTER]
• [ENTER]
• dir
• [ENTER]
• [ENTER]

Which generates output like

2008-06-08 18:13:12
PS>
2008-06-08 18:13:23
PS>
2008-06-08 18:13:23
PS>dir

    Directory: Microsoft.PowerShell.Core\FileSystem::G:\PSTest

Mode                LastWriteTime     Length Name
—-                ————-     —— —-
-a—         6/24/2007  10:06 PM    2013184 AdFind.exe
-a—          6/8/2008  10:37 AM       1559 PSSpeed.ps1
-a—          6/8/2008  10:33 AM       2338 Test-DSProtocalsSP.ps1

2008-06-08 18:13:23
PS>
2008-06-08 18:13:23
PS>

I think anyone who looks at it should be comfortable with this method. If not, please let me know what you aren’t comfortable about.

 

 

B. So my solution for the second issue is probably pretty obvious after seeing the solution to the first… Have a notepad document with some commands all ready to cut and paste into the PoS window in one fell swoop. That looks something like

• [ENTER]
• [ENTER]
• adfind -default -f objectclass=* -c
• adfind -default -f objectclass=* -c
• [ENTER]
• [ENTER]
• .\Test-DSProtocalsSP.ps1
• .\Test-DSProtocalsSP.ps1
• [ENTER]
• [ENTER]

 

and a “10 count run”

• [ENTER]
• [ENTER]
• adfind -default -f objectclass=* -c
• adfind -default -f objectclass=* -c
• adfind -default -f objectclass=* -c
• adfind -default -f objectclass=* -c
• adfind -default -f objectclass=* -c
• adfind -default -f objectclass=* -c
• adfind -default -f objectclass=* -c
• adfind -default -f objectclass=* -c
• adfind -default -f objectclass=* -c
• adfind -default -f objectclass=* -c
• [ENTER]
• [ENTER]
• .\Test-DSProtocalsSP.ps1
• .\Test-DSProtocalsSP.ps1
• .\Test-DSProtocalsSP.ps1
• .\Test-DSProtocalsSP.ps1
• .\Test-DSProtocalsSP.ps1
• .\Test-DSProtocalsSP.ps1
• .\Test-DSProtocalsSP.ps1
• .\Test-DSProtocalsSP.ps1
• .\Test-DSProtocalsSP.ps1
• .\Test-DSProtocalsSP.ps1
• [ENTER]
• [ENTER]

 

2. Testing environment

I think testing against a 700k user environment is a bit extreme as there aren’t but a handful of AD Implementations out there that come anywhere near that but maybe it is good in that it will help stabilize any time variance issues resulting from spin up time for the app/script. I.E. If you have a second of overhead for starting an app, the more objects you have to pull, the smaller the percentage that overhead will be of the total execution time. I kind of think this tends to help PoS more than a native app because a native app has very little spin up overhead relative to PoS script or .NET but I will go with it. If anything, launching AdFind from within PoS likely has more overhead for launch than launching a PoS script from PoS. If someone wants to test on different sized environments, knock yourself out. I am already spending too much time on this.

I used AdMod to create 700k test users on my test domain with the following command:

admod -sc adau:70000;MyPassword1!;cn=PoSTest,ou=PoSTest,dc=test,dc=loc

I am running all of my tests against a virtual DC loaded with Windows Server 2003 SP2; it is one of 3 virtuals currently running on an Intel Quad Core Server box I build specifically for running virtuals using VMWARE Server. The RAM allocated (256MB) is not even close enough to cache the entire DIT (~2.75GB) even if I enabled /3GB (which I didn’t, no point…). The actual code is running on a real physical machine that has x86 XP SP2 on it and is a AMD Athlon 64 X2 4200+ Dual Core proc. Underlying network is 100Mbs with most network traffic quiesced for the testing period.

I am using the publicly available version of AdFind – V01.37.00 compiled on June 24, 2007.

PS>filever adfind.exe
–a– W32i   APP ENU     1.37.0.1604 shp  2,013,184 06-24-2007 adfind.exe

I am using the PoS Script that Brandon posted on his blog…Here it is again for completeness. Brandon, note a good modification to the script would be to output what DC it is connecting to to do the work so you know if it is consistently connecting to the same place and that AdFind and the script are connecting to the same place. I validated that it appeared to be using the same DC as AdFind by doing some network tracing. That shouldn’t be needed and honestly there should be a way to specify the domain/DC to use to make sure the same source is used consistently.

Test-DSProtocalsSP.ps1

[System.Reflection.assembly]::LoadWithPartialName(“system.directoryservices.protocols”) | Out-Null
$domain = ([ADSI]””).distinguishedName -replace  “,”,”.” -replace “dc=”,””
$DomainDN = “DC=” + $Domain -replace “\.”,”,DC=”
[int]$pageCount = 0
[int]$pageSize = 1000
[int]$count = 0
$connection = New-Object System.DirectoryServices.Protocols.LdapConnection($domain) 
$subtree = [System.DirectoryServices.Protocols.SearchScope]”Subtree”
$filter = “(objectclass=user)”
$searchRequest = New-Object System.DirectoryServices.Protocols.SearchRequest($DomainDN,$filter,$subtree,@(“1.1”)) 
$pagedRequest = New-Object System.DirectoryServices.Protocols.PageResultRequestControl($pageSize)
$searchRequest.Controls.add($pagedRequest) | out-null
$searchOptions = new-object System.DirectoryServices.Protocols.SearchOptionsControl([System.DirectoryServices.Protocols.SearchOption]::DomainScope)
$searchRequest.Controls.Add($searchOptions) | out-null
while ($true)
{
    ## increment the pageCount by 1
    $pageCount++
    ## cast the directory response into a
    ## SearchResponse object
    $searchResponse = $connection.SendRequest($searchRequest)
    ## verify support for this advanced search operation
    if (($searchResponse.Controls.Length -lt 1) -or
        !($searchResponse.Controls[0] -is [System.DirectoryServices.Protocols.PageResultResponseControl]))
    {
        Write-Host “The server cannot page the result set”
        return;
    }
    ## cast the diretory control into
    ## a PageResultResponseControl object.
    $pageResponse = $searchResponse.Controls[0]
    ## display the retrieved page number and the number of
    ## directory entries in the retrieved page                   
    #”Page:{0} Contains {1} response entries” -f $pageCount,$searchResponse.entries.count
    $count += $searchResponse.entries.count
    ## display the entries within this page
    ## foreach($entry in $searchResponse.entries){$entry.DistinguishedName}
    ## if this is true, there
    ## are no more pages to request
    if ($pageResponse.Cookie.Length -eq 0){write-Host $count;break}
    ## set the cookie of the pageRequest equal to the cookie
    ## of the pageResponse to request the next page of data
    ## in the send request
    $pagedRequest.Cookie = $pageResponse.Cookie
}

 

3. Considerable performance hit on the machine running the tools…. Based on .FAT[11] isn’t it???

This one is actually pretty humourous, doesn’t take much to see what is happening… It shows quite quickly and easily one of my issues with using something other than native code; especially .NET/PoS. This is what you get as you abstract and bloat… This is a part of the reason why it is slow overall, it beats the machine up.

 

Figure 1 shows my machine at “idle”. When I watched it I saw CPU usage bumps between 0% and 5% with spikes up to about 15%.

                                                     [Figure 1]

 

Figure 2 shows AdFind running the command “adfind -default -f objectclass=* -c” which counts the objects in the domain NC. When I watched it I saw CPU usage bumps between about 4% and 11% with spikes up to about 18%.

                                                     [Figure 2]

 

 

Figure 3 shows Brandon’s PoS script counting the objects in the domain NC. When I watched it I saw CPU usage bumps between 20% and 45% with spikes up to around 50%.

                                                     [Figure 3]

 

If you don’t like pretty pictures and prefer hard text data instead, here is output from typeperf… 35 one second samples from each state…

 

This is when idling

“(PDH-CSV 4.0)”,”\\SFMXP32\processor(_total)\% processor time”

“06/08/2008 17:00:04.789″,”0.000000”
“06/08/2008 17:00:05.789″,”0.000000”
“06/08/2008 17:00:06.789″,”0.000000”
“06/08/2008 17:00:07.789″,”0.000000”
“06/08/2008 17:00:08.789″,”0.774265”
“06/08/2008 17:00:09.789″,”0.000000”
“06/08/2008 17:00:10.789″,”0.000000”
“06/08/2008 17:00:11.789″,”0.000000”
“06/08/2008 17:00:12.789″,”0.000000”
“06/08/2008 17:00:13.789″,”0.000000”
“06/08/2008 17:00:14.789″,”0.774265”
“06/08/2008 17:00:15.789″,”0.774265”
“06/08/2008 17:00:16.789″,”0.000000”
“06/08/2008 17:00:17.789″,”0.774265”
“06/08/2008 17:00:18.789″,”0.000000”
“06/08/2008 17:00:19.788″,”0.000000”
“06/08/2008 17:00:20.788″,”2.336875”
“06/08/2008 17:00:21.788″,”0.774265”
“06/08/2008 17:00:22.788″,”2.336875”
“06/08/2008 17:00:23.788″,”0.000000”
“06/08/2008 17:00:24.788″,”0.000000”
“06/08/2008 17:00:25.788″,”0.000000”
“06/08/2008 17:00:26.788″,”0.000000”
“06/08/2008 17:00:27.788″,”0.000000”
“06/08/2008 17:00:28.788″,”0.000000”
“06/08/2008 17:00:29.788″,”0.774265”
“06/08/2008 17:00:30.788″,”0.000000”
“06/08/2008 17:00:31.788″,”1.555570”
“06/08/2008 17:00:32.788″,”0.000000”
“06/08/2008 17:00:33.787″,”0.774265”
“06/08/2008 17:00:34.787″,”0.000000”
“06/08/2008 17:00:35.787″,”0.000000”
“06/08/2008 17:00:36.787″,”0.000000”
“06/08/2008 17:00:37.787″,”0.000000”
“06/08/2008 17:00:38.787″,”0.000000”
“06/08/2008 17:00:39.787″,”0.000000”
“06/08/2008 17:00:40.787″,”0.000000”
“06/08/2008 17:00:41.787″,”0.000000”
“06/08/2008 17:00:42.787″,”0.000000”
“06/08/2008 17:00:43.787″,”0.000000”
“06/08/2008 17:00:44.787″,”0.774265”

 

This is when AdFind was running

“(PDH-CSV 4.0)”,”\\SFMXP32\processor(_total)\% processor time”

“06/08/2008 17:01:06.785″,”1.555570”
“06/08/2008 17:01:07.785″,”6.243400”
“06/08/2008 17:01:08.785″,”3.899485”
“06/08/2008 17:01:09.785″,”8.587315”
“06/08/2008 17:01:10.785″,”10.931230”
“06/08/2008 17:01:11.800″,”7.685809”
“06/08/2008 17:01:12.800″,”10.931230”
“06/08/2008 17:01:13.800″,”14.056450”
“06/08/2008 17:01:14.800″,”9.368620”
“06/08/2008 17:01:15.800″,”15.619060”
“06/08/2008 17:01:16.800″,”5.462095”
“06/08/2008 17:01:17.800″,”9.368620”
“06/08/2008 17:01:18.800″,”13.275145”
“06/08/2008 17:01:19.800″,”9.368620”
“06/08/2008 17:01:20.800″,”11.712535”
“06/08/2008 17:01:21.800″,”5.462095”
“06/08/2008 17:01:22.800″,”10.149925”
“06/08/2008 17:01:23.800″,”6.243400”
“06/08/2008 17:01:24.799″,”6.243400”
“06/08/2008 17:01:25.799″,”9.368620”
“06/08/2008 17:01:26.799″,”8.587315”
“06/08/2008 17:01:27.799″,”9.368620”
“06/08/2008 17:01:28.799″,”10.149925”
“06/08/2008 17:01:29.799″,”11.712535”
“06/08/2008 17:01:30.799″,”14.837755”
“06/08/2008 17:01:31.799″,”5.462095”
“06/08/2008 17:01:32.799″,”9.368620”
“06/08/2008 17:01:33.799″,”6.243400”
“06/08/2008 17:01:34.799″,”2.336875”
“06/08/2008 17:01:35.799″,”0.774265”
“06/08/2008 17:01:36.799″,”3.118180”
“06/08/2008 17:01:37.799″,”1.555570”
“06/08/2008 17:01:38.799″,”2.336875”
“06/08/2008 17:01:39.798″,”4.680790”
“06/08/2008 17:01:40.798″,”5.462095”
“06/08/2008 17:01:41.798″,”9.368620”
“06/08/2008 17:01:42.798″,”3.118180”

 

This is when the PoS Script was running

“(PDH-CSV 4.0)”,”\\SFMXP32\processor(_total)\% processor time”

“06/08/2008 17:09:17.344″,”36.918636”
“06/08/2008 17:09:18.407″,”41.786947”
“06/08/2008 17:09:19.422″,”43.072915”
“06/08/2008 17:09:20.469″,”44.772231”
“06/08/2008 17:09:21.516″,”35.816377”
“06/08/2008 17:09:22.563″,”33.083524”
“06/08/2008 17:09:23.594″,”36.918636”
“06/08/2008 17:09:24.594″,”29.682550”
“06/08/2008 17:09:25.594″,”33.589075”
“06/08/2008 17:09:26.609″,”29.540494”
“06/08/2008 17:09:27.656″,”29.540494”
“06/08/2008 17:09:28.734″,”41.300215”
“06/08/2008 17:09:29.734″,”36.359156”
“06/08/2008 17:09:30.797″,”34.086269”
“06/08/2008 17:09:31.812″,”31.533642”
“06/08/2008 17:09:32.812″,”28.901245”
“06/08/2008 17:09:33.828″,”33.072211”
“06/08/2008 17:09:34.859″,”33.328640”
“06/08/2008 17:09:35.859″,”34.610781”
“06/08/2008 17:09:36.905″,”34.086269”
“06/08/2008 17:09:37.952″,”35.816377”
“06/08/2008 17:09:38.952″,”35.151685”
“06/08/2008 17:09:40.015″,”32.348178”
“06/08/2008 17:09:41.046″,”39.547983”
“06/08/2008 17:09:42.093″,”38.230946”
“06/08/2008 17:09:43.139″,”40.904931”
“06/08/2008 17:09:44.186″,”38.230946”
“06/08/2008 17:09:45.217″,”39.839515”
“06/08/2008 17:09:46.233″,”36.918636”
“06/08/2008 17:09:47.233″,”46.089955”
“06/08/2008 17:09:48.280″,”41.786947”
“06/08/2008 17:09:49.280″,”27.338635”
“06/08/2008 17:09:50.280″,”38.276905”
“06/08/2008 17:09:51.279″,”39.839515”
“06/08/2008 17:09:52.279″,”32.807770”
“06/08/2008 17:09:53.295″,”31.533642”
“06/08/2008 17:09:54.295″,”41.402125”
“06/08/2008 17:09:55.342″,”49.250159”
“06/08/2008 17:09:56.342″,”34.610781”
“06/08/2008 17:09:57.388″,”39.389672”
“06/08/2008 17:09:58.388″,”32.807770”
“06/08/2008 17:09:59.420″,”41.662560”
“06/08/2008 17:10:00.435″,”42.533268”
“06/08/2008 17:10:01.497″,”39.389672”
“06/08/2008 17:10:02.513″,”31.533642”
“06/08/2008 17:10:03.513″,”32.571011”
“06/08/2008 17:10:04.575″,”40.904931”
“06/08/2008 17:10:05.575″,”32.807770”
“06/08/2008 17:10:06.575″,”32.026465”
“06/08/2008 17:10:07.575″,”9.368620”
“06/08/2008 17:10:08.575″,”27.338635”
“06/08/2008 17:10:09.591″,”37.687921”
“06/08/2008 17:10:10.637″,”41.786947”
“06/08/2008 17:10:11.653″,”39.995776”
“06/08/2008 17:10:12.684″,”46.965963”
“06/08/2008 17:10:13.731″,”58.820630”
“06/08/2008 17:10:14.762″,”39.995776”
“06/08/2008 17:10:15.778″,”39.547983”
“06/08/2008 17:10:16.840″,”40.147302”
“06/08/2008 17:10:17.871″,”37.495600”

Plugged into Excel, these are the stats for those 35 data points

Idle

• Min: 0
• Max: 2.336875
• Avg: 0.332834
• Median: 0
• Skew: 2.156378
• Variance: 0.401792

AdFind

• Min: 0.774265
• Max: 15.61906
• Avg: 7.75793
• Median: 8.587315
• Skew: 0.05928
• Variance: 15.36671

PoS

• Min: 27.33864
• Max: 46.08996
• Avg: 36.14655
• Median: 35.81638
• Skew: 0.157006
• Variance: 21.74553

 

4. Network Utilization

After running a couple of tests and going out and working in the yard for a bit I thought… hmmm With the results I saw, I bet the network utilization numbers are off too between AdFind and the script… Sure enough.

 

Figure 4 is idle use

                                                     [Figure 4]

 

Figure 5 is AdFind use

                                                     [Figure 5]

 

Figure 6 is the PoS Script.

                                                     [Figure 6]

 

Note the percentage range on the graphs… The AdFind graph has a range of 0-25% and the PoS graph has a range of 0-5%…

 

Again with some typeperf stats… 35 data points for each state again….

 

This is when idling…

“(PDH-CSV 4.0)”,”\\SFMXP32\network interface(Realtek RTL8168_8111 PCI-E Gigabit Ethernet NIC – Packet Scheduler Miniport)\Bytes Total/sec”

06/08/2008 20:21:15.101,”0.000000″
06/08/2008 20:21:16.101,”0.000000″
06/08/2008 20:21:17.101,”0.000000″
06/08/2008 20:21:18.101,”0.000000″
06/08/2008 20:21:19.101,”0.000000″
06/08/2008 20:21:20.116,”0.000000″
06/08/2008 20:21:21.116,”0.000000″
06/08/2008 20:21:22.116,”0.000000″
06/08/2008 20:21:23.116,”0.000000″
06/08/2008 20:21:24.116,”0.000000″
06/08/2008 20:21:25.116,”0.000000″
06/08/2008 20:21:26.132,”0.000000″
06/08/2008 20:21:27.132,”0.000000″
06/08/2008 20:21:28.132,”0.000000″
06/08/2008 20:21:29.132,”0.000000″
06/08/2008 20:21:30.132,”0.000000″
06/08/2008 20:21:31.132,”0.000000″
06/08/2008 20:21:32.132,”0.000000″
06/08/2008 20:21:33.132,”0.000000″
06/08/2008 20:21:34.147,”0.000000″
06/08/2008 20:21:35.147,”0.000000″
06/08/2008 20:21:36.147,”0.000000″
06/08/2008 20:21:37.147,”0.000000″
06/08/2008 20:21:38.147,”409.193170″
06/08/2008 20:21:39.147,”0.000000″
06/08/2008 20:21:40.147,”0.000000″
06/08/2008 20:21:41.147,”0.000000″
06/08/2008 20:21:42.163,”0.000000″
06/08/2008 20:21:43.163,”0.000000″
06/08/2008 20:21:44.163,”0.000000″
06/08/2008 20:21:45.163,”0.000000″
06/08/2008 20:21:46.163,”0.000000″
06/08/2008 20:21:47.163,”0.000000″
06/08/2008 20:21:48.163,”0.000000″
06/08/2008 20:21:49.163,”0.000000″

 

AdFind query…

“(PDH-CSV 4.0)”,”\\SFMXP32\network interface(Realtek RTL8168_8111 PCI-E Gigabit Ethernet NIC – Packet Scheduler Miniport)\Bytes Total/sec”

06/08/2008 20:22:48.303,”432.148631″
06/08/2008 20:22:49.303,”7812.669507″
06/08/2008 20:22:50.319,”215500.866875″
06/08/2008 20:22:51.319,”675597.824476″
06/08/2008 20:22:52.319,”210349.356274″
06/08/2008 20:22:53.319,”1266930.446812″
06/08/2008 20:22:54.319,”1416464.689079″
06/08/2008 20:22:55.319,”1558286.015944″
06/08/2008 20:22:56.319,”425118.163681″
06/08/2008 20:22:57.334,”1344444.782983″
06/08/2008 20:22:58.334,”1137181.434605″
06/08/2008 20:22:59.334,”1597069.087841″
06/08/2008 20:23:00.334,”1312058.658551″
06/08/2008 20:23:01.334,”1530619.724371″
06/08/2008 20:23:02.334,”1676687.003461″
06/08/2008 20:23:03.334,”1603403.974700″
06/08/2008 20:23:04.334,”1676201.171529″
06/08/2008 20:23:05.350,”1755335.554489″
06/08/2008 20:23:06.350,”1815894.653956″
06/08/2008 20:23:07.350,”1748979.095744″
06/08/2008 20:23:08.350,”1457658.560362″
06/08/2008 20:23:09.350,”1749027.180590″
06/08/2008 20:23:10.350,”1748969.577365″
06/08/2008 20:23:11.350,”1602738.860017″
06/08/2008 20:23:12.350,”1880224.306196″
06/08/2008 20:23:13.366,”1543784.545800″
06/08/2008 20:23:14.366,”1528733.402130″
06/08/2008 20:23:15.366,”1748985.669767″
06/08/2008 20:23:16.365,”1675179.234176″
06/08/2008 20:23:17.365,”1750306.711728″
06/08/2008 20:23:18.365,”1374845.844406″
06/08/2008 20:23:19.365,”1975074.793721″
06/08/2008 20:23:20.381,”1457283.676124″
06/08/2008 20:23:21.381,”1603445.281594″
06/08/2008 20:23:22.381,”1674138.066714″

 

And PoS script

“(PDH-CSV 4.0)”,”\\SFMXP32\network interface(Realtek RTL8168_8111 PCI-E Gigabit Ethernet NIC – Packet Scheduler Miniport)\Bytes Total/sec”

06/08/2008 20:24:23.537,”95271.394985″
06/08/2008 20:24:24.537,”152096.806819″
06/08/2008 20:24:25.537,”304867.276069″
06/08/2008 20:24:26.537,”229631.839613″
06/08/2008 20:24:27.537,”76356.320892″
06/08/2008 20:24:28.553,”282718.881348″
06/08/2008 20:24:29.553,”212996.840599″
06/08/2008 20:24:30.553,”428616.679015″
06/08/2008 20:24:31.553,”288234.300414″
06/08/2008 20:24:32.553,”288276.315703″
06/08/2008 20:24:33.553,”287835.901916″
06/08/2008 20:24:34.568,”144267.514096″
06/08/2008 20:24:35.568,”288038.282918″
06/08/2008 20:24:36.568,”287903.691420″
06/08/2008 20:24:37.568,”215894.243299″
06/08/2008 20:24:38.568,”288022.088767″
06/08/2008 20:24:39.584,”287852.416168″
06/08/2008 20:24:40.584,”287907.460559″
06/08/2008 20:24:41.584,”287867.971897″
06/08/2008 20:24:42.584,”216662.763604″
06/08/2008 20:24:43.584,”359322.953951″
06/08/2008 20:24:44.584,”216204.281269″
06/08/2008 20:24:45.599,”287921.254846″
06/08/2008 20:24:46.599,”216670.797928″
06/08/2008 20:24:47.599,”431409.468785″
06/08/2008 20:24:48.599,”216048.609884″
06/08/2008 20:24:49.599,”360909.160668″
06/08/2008 20:24:50.599,”359313.537159″
06/08/2008 20:24:51.599,”216058.961104″
06/08/2008 20:24:52.615,”287855.543216″
06/08/2008 20:24:53.615,”362659.902837″
06/08/2008 20:24:54.615,”292073.121217″
06/08/2008 20:24:55.615,”292124.653467″
06/08/2008 20:24:56.615,”219204.028101″
06/08/2008 20:24:57.615,”219607.804823″

 

Plugged into Excel, these are the stats for those 35 data points

Idle

• Min: 0
• Max: 409.19317
• Avg: 11.691233
• Median: 0
• Skew: 5.9160798
• Variance: 4783.9729

AdFind

• Min: 432.15
• Max: 1,975,074.79  (1.88 MB/s)
• Avg: 1,364,136.09 (1.30 MB/s)
• Median: 1,558,286.02 (1.49 MB/s)
• Skew: -1.55
• Variance: 301,963,579,984.33

PoS

• Min: 76,356.32
• Max: 431,409.47 (.41 MB/s)
• Avg: 265,391.52 (.25 MB/s)
• Median: 287,855.54 (.27 MB/s)
• Skew: -0.21
• Variance: 6,301,469,856.37

 

Average of 1.3 MB per second versus .25  MB per second… AdFind is pulling the data 5 times faster… This absolutely does not support what Brandon saw in his tests which makes me question what is different or is the PoS timing script he is using that bad? Both tools have to pull the same amount of data to get object counts, there are no shortcuts… If AdFind pulls the data 5 times faster, it has the potential to be at least 5 times faster at execution.

 

5. Umm there is a problem in the PoS Script… It doesn’t seen to know how to count correctly.

Here is what AdFind says the count is… 711387

Here is what the script says the count is… 711145

Looking at the script I am pretty sure I know what is wrong but will let Brandon sort it out.  Good learning exercise… 😉

 

6. The PoS doesn’t seem so fast in relation to AdFind…  (at least to me)

So here are the results of the actual tests…

First the two count run…

 

2008-06-08 20:52:45
PS>
2008-06-08 20:52:46
PS>
2008-06-08 20:52:46
PS>adfind -default -f objectclass=* -c

AdFind V01.37.00cpp Joe Richards (joe@joeware.net) June 2007

Using server: TEST-DC1.test.loc:389
Directory: Windows Server 2003
Base DN: DC=test,DC=loc

711387 Objects returned
2008-06-08 20:53:19
PS>adfind -default -f objectclass=* -c

AdFind V01.37.00cpp Joe Richards (joe@joeware.net) June 2007

Using server: TEST-DC1.test.loc:389
Directory: Windows Server 2003
Base DN: DC=test,DC=loc

711387 Objects returned
2008-06-08 20:54:01
PS>
2008-06-08 20:54:01
PS>
2008-06-08 20:54:01
PS>.\Test-DSProtocalsSP.ps1
711145
2008-06-08 20:57:22
PS>.\Test-DSProtocalsSP.ps1
711145
2008-06-08 21:00:48
PS>
2008-06-08 21:00:48
PS>
2008-06-08 21:00:48
PS>

Here are the numbers

AdFind

1. 20:52:46 – 20:53:19  = 33 seconds
2. 20:53:19 – 20:54:01 = 42 seconds

 

PoS

1. 20:54:01 – 20:57:22 = 201 seconds (3 minutes 21 seconds)
2. 20:57:22 – 21:00:48 = 206 seconds (3 minutes 26 seconds)

 

This is showing AdFind is roughly 4.5-6.25 times faster than the PoS script which is what the network traffic implied.

 

So let’s look at the 10 count test and see if we have consistency…

 

2008-06-08 21:01:27
PS>
2008-06-08 21:02:08
PS>
2008-06-08 21:02:08
PS>adfind -default -f objectclass=* -c

AdFind V01.37.00cpp Joe Richards (joe@joeware.net) June 2007

Using server: TEST-DC1.test.loc:389
Directory: Windows Server 2003
Base DN: DC=test,DC=loc

711387 Objects returned
2008-06-08 21:02:49
PS>adfind -default -f objectclass=* -c

AdFind V01.37.00cpp Joe Richards (joe@joeware.net) June 2007

Using server: TEST-DC1.test.loc:389
Directory: Windows Server 2003
Base DN: DC=test,DC=loc

711387 Objects returned
2008-06-08 21:03:36
PS>adfind -default -f objectclass=* -c

AdFind V01.37.00cpp Joe Richards (joe@joeware.net) June 2007

Using server: TEST-DC1.test.loc:389
Directory: Windows Server 2003
Base DN: DC=test,DC=loc

711387 Objects returned
2008-06-08 21:04:22
PS>adfind -default -f objectclass=* -c

AdFind V01.37.00cpp Joe Richards (joe@joeware.net) June 2007

Using server: TEST-DC1.test.loc:389
Directory: Windows Server 2003
Base DN: DC=test,DC=loc

711387 Objects returned
2008-06-08 21:05:06
PS>adfind -default -f objectclass=* -c

AdFind V01.37.00cpp Joe Richards (joe@joeware.net) June 2007

Using server: TEST-DC1.test.loc:389
Directory: Windows Server 2003
Base DN: DC=test,DC=loc

711387 Objects returned
2008-06-08 21:05:52
PS>adfind -default -f objectclass=* -c

AdFind V01.37.00cpp Joe Richards (joe@joeware.net) June 2007

Using server: TEST-DC1.test.loc:389
Directory: Windows Server 2003
Base DN: DC=test,DC=loc

711387 Objects returned
2008-06-08 21:06:38
PS>adfind -default -f objectclass=* -c

AdFind V01.37.00cpp Joe Richards (joe@joeware.net) June 2007

Using server: TEST-DC1.test.loc:389
Directory: Windows Server 2003
Base DN: DC=test,DC=loc

711387 Objects returned
2008-06-08 21:07:25
PS>adfind -default -f objectclass=* -c

AdFind V01.37.00cpp Joe Richards (joe@joeware.net) June 2007

Using server: TEST-DC1.test.loc:389
Directory: Windows Server 2003
Base DN: DC=test,DC=loc

711387 Objects returned
2008-06-08 21:08:13
PS>adfind -default -f objectclass=* -c

AdFind V01.37.00cpp Joe Richards (joe@joeware.net) June 2007

Using server: TEST-DC1.test.loc:389
Directory: Windows Server 2003
Base DN: DC=test,DC=loc

711387 Objects returned
2008-06-08 21:09:02
PS>adfind -default -f objectclass=* -c

AdFind V01.37.00cpp Joe Richards (joe@joeware.net) June 2007

Using server: TEST-DC1.test.loc:389
Directory: Windows Server 2003
Base DN: DC=test,DC=loc

711387 Objects returned
2008-06-08 21:09:47
PS>
2008-06-08 21:09:47
PS>
2008-06-08 21:09:47
PS>.\Test-DSProtocalsSP.ps1
711145
2008-06-08 21:13:17
PS>.\Test-DSProtocalsSP.ps1
711145
2008-06-08 21:16:47
PS>.\Test-DSProtocalsSP.ps1
711145
2008-06-08 21:20:14
PS>.\Test-DSProtocalsSP.ps1
711145
2008-06-08 21:23:49
PS>.\Test-DSProtocalsSP.ps1
711145
2008-06-08 21:27:18
PS>.\Test-DSProtocalsSP.ps1
711145
2008-06-08 21:30:45
PS>.\Test-DSProtocalsSP.ps1
711145
2008-06-08 21:34:14
PS>.\Test-DSProtocalsSP.ps1
711145
2008-06-08 21:37:50
PS>.\Test-DSProtocalsSP.ps1
711145
2008-06-08 21:41:22
PS>.\Test-DSProtocalsSP.ps1
711145
2008-06-08 21:45:22
PS>
2008-06-08 21:45:22
PS>
2008-06-08 21:45:22
PS>

 

Here are the numbers

 

AdFind

1. 21:02:08 – 21:02:49 = 41 seconds
2. 21:02:49 – 21:03:36 = 47 seconds
3. 21:03:36 – 21:04:22 = 46 seconds
4. 21:04:22 – 21:05:06 = 44 seconds
5. 21:05:06 – 21:05:52 = 46 seconds
6. 21:05:52 – 21:06:38 = 46 seconds
7. 21:06:38 – 21:07:25 = 47 seconds
8. 21:07:25 – 21:08:13 = 48 seconds
9. 21:08:13 – 21:09:02 = 49 seconds
10. 21:09:02 – 21:09:47 = 45 seconds

 

PoS

1. 21:09:47 – 21:13:17 = 210 seconds (3 minutes 30 seconds)
2. 21:13:17 – 21:16:47 = 210 seconds (3 minutes 30 seconds)
3. 21:16:47 – 21:20:14 = 207 seconds (3 minutes 27 seconds)
4. 21:20:14 – 21:23:49 = 215 seconds (3 minutes 35 seconds)
5. 21:23:49 – 21:27:18 = 209 seconds (3 minutes 29 seconds)
6. 21:27:18 – 21:30:45 = 207 seconds (3 minutes 27 seconds)
7. 21:30:45 – 21:34:14 = 209 seconds (3 minutes 29 seconds)
8. 21:34:14 – 21:37:50 = 216 seconds (3 minutes 36 seconds)
9. 21:37:50 – 21:41:22 = 212 seconds (3 minutes 32 seconds)
10. 21:41:22 – 21:45:22 = 240 seconds (4 minutes 0 seconds)

 

After seeing those numbers I thought wow and then tried it all again but flipped it around and had PoS run first and then AdFind. In summary the PoS stuff started at 22:51:49 and finished at 23:30:22, that is 37 minutes and 33 seconds or 2253 seconds or an average of 225.3 seconds for 10 runs (compared to 21:09:47 to 21:45:22 which is 35 minutes and 35 seconds or 2135 seconds or an average of 213.5 seconds for 10 runs). The AdFind stuff started at 23:30:22 and finished at 23:37:59, that is 7 minutes 37 seconds or 457 seconds or an average of 45.7 seconds for 10 runs (compared to 21:02:08 to 21:09:47 which is 7 minutes 39 seconds or 459 seconds or an average of 45.9 seconds for 10 runs). So we are seeing that AdFind is between 4.22 and 5.85 times faster than PoS.

 

I consider those numbers to be very consistent as well as very telling. I can’t for the life of me explain why Brandon and my numbers are so dramatically different other than maybe trying to use a PoS script to measure the perf of AdFind and the other PoS Script may not be the optimal test framework and is maybe introducing some other errors? Alternately maybe he has some special tuning for .NET stuff? That shouldn’t be needed, but I know I don’t have any special tunings, my machine has whatever the .NET stuff loads as is and PowerShell loaded on top. I guess possibly he changed the script and didn’t post the latest version to his blog… I don’t know. I just know where he was seeing seconds of difference, I see no way of that occurring.

 

Thoughts?

 

    joe

 

 

[1] I think it sort of went like this… He maybe got tired of hearing about PowerShell being fat and slow (ditto .NET) so set out to prove that it could be as performant or maybe close to as performant as native code. I am just guessing based on my knowledge of Brandon and what he has written on this testing. I know Brandon sometimes likes to fight for the sake of fighting[2]… not a problem, I am fine with that. I debated with him in person for several days at the last MVP summit.

[2] Yes you really do Brandon.

[3] FWIW, I think most folks are just going to up and assume .NET and PoS are going to be slower and accept it for what it is; people don’t use those technologies because they want raw run performance, they want ease of getting to what they want to get to[4].

[4] I am, despite what some may think, ok with that. In fact, I often tell people who are starting out now in DS programming to look at the .NET stuff instead of the native stuff[5] because quite honestly with the exception of true professional programmers I think the raw LDAP and native code stuff might be a bit much for many of the computer people of today… However, this doesn’t mean I am looking at using it. I am already spun up on the native and raw LDAP stuff.

[5] Using the .NET Framework will be easier to spin up and go for most of the folks in the field today who aren’t already seasoned programmers (with real language backgrounds… this IMO excludes VB from discussion); especially admins.  However, I don’t want them writing any serious app that is doing a ton of work that I will be dependent on using heavily. Using it to get some basic stuff going or stuff that I never have to use I have no problem with.

[6] That is because it means the “next generation” programming mechanisms aren’t going to make us all upgrade our hardware yet again… How does it go… Something like…  Intel Giveth us Speed, Microsoft takes it away… In all honesty, I don’t expect to see .NET being truly performant to any well written native code standards until it is embedded in the core and absolutely HAS to be performant. Note the key use of “well written”. Just because someone writes in native code, doesn’t mean they write well and for those people that don’t write well, they likely will do better writing in .NET. So anyway, I want to see .NET and PoS work well and efficiently because it will likely be heavily used and I would rather people not be running a bunch of slow crap out there as I may end up dealing with it one way or another.

[7] We are slowly moving out from the intricacies of the hardware abstracting more and more. It is a curve where on the far left we have the binary machine language which is all 0’s and 1’s and as you move towards the right you get to more and more complexity and robustness and hopefully ease of use. But also as you move to the right while you gain the ease of use abstraction, you pay more and more penalty in performance for that abstraction. First step after machine language… Assembler, then Macro Assembler, and then say C and then C++ and FORTRAN and COBOL, etc etc etc… We have moved further and further right in the curve[8] as we “evolve” in our use of computers and as the right becomes more acceptable either by becoming more performant from learning and making things more efficient or we just are more accepting of the trade offs because computers get faster and what ran slow yesterday runs faster today or we just can’t be bothered to worry about the speed period.

[8] The .NET framework is on the far right side of this curve right now and may or may not be what we go to next as the de facto for things that native C++, IMO, is now. I don’t think it has been proven conclusively one way or the other yet. Java has been claiming it is the de facto now for at least 10 years. I still haven’t written a line of Java though back in the late 90’s all my “cool” friends said I would, it was just a matter of time…. “You just wait joe… No one will be writing anything in C++ in 10 years… it will all be Java[9] and CORBA[10]…”

[9] The .NET stuff, at least to me, is Microsoft’s “Java”. Might as well called it MSava (sic) in my mind. 🙂 Anyway now all my .NET friends say the same things to me my Java friends said. Granted, they are more likely to be correct, but not guaranteed to be…

[10] Interestingly, at least to me, is that now right around 10 years later most people in the computer world know of and have heard of Java but say “What the frack is CORBA???”

[11] I can’t take the credit for .FAT, but I like it just the same. 🙂

A lot of times when people run into issues with LDAP based apps, one of the troubleshooting steps I recommend is to do a network trace and look at the LDAP traffic and then I hear… Hey, I try to but it looks like gibberish and WireShark says it can’t be decoded or something… By this I think they mean it looks something like

Lightweight-Directory-Access-Protocol
    BER Error: Sequence expected but Class:0(UNIVERSAL) PC:0 Tag:0 was unexpected

0000  00 50 8d 91 0b d2 00 0c 29 f4 7b 5e 08 00 45 00   .P……).{^..E.
0010  05 dc 07 ab 40 00 80 06 6b 2e c0 a8 00 78 c0 a8   ….@…k….x..
0020  00 7a 01 85 04 6c e4 78 1a 2e 35 8f ea 5b 50 10   .z…l.x..5..[P.
0030  f7 5d 83 2f 00 00 00 00 0a 9d 01 00 00 00 f5 18   .]./…………
0040  cf 41 7a b3 3f da 01 00 00 00 11 de f4 b8 eb 4c   .Az.?……….L
0050  28 e8 b2 c3 e0 69 20 28 f6 b0 90 1b ec b8 05 4f   (….i (…….O
0060  80 bb 82 75 af a7 26 68 e6 d5 35 2b 56 04 ba 11   …u..&h..5+V…
0070  30 16 00 fe 8d 16 85 e7 da 62 97 d5 86 f9 bb 59   0……..b…..Y
0080  00 d7 59 60 12 36 fe b6 b5 82 bb 2b ec cf 3b 6a   ..Y`.6…..+..;j
0090  42 6b 6b dd d3 a3 e4 63 42 8a 0b ae d1 bc 5a 40   Bkk….cB…..Z@
00a0  46 de 1e 78 01 bc c1 ad ec 36 80 db cc eb c2 f9   F..x…..6……
00b0  ba 85 83 a8 f5 22 bf cc 7b 97 29 9e e0 18 b2 fc   …..”..{.)…..
00c0  c2 bd 01 2a a6 83 33 55 a3 57 e1 21 65 4d f9 08   …*..3U.W.!eM..
00d0  8d ff dc 25 0e 3d 93 cc 4c 34 4c 1f f1 17 39 be   …%.=..L4L…9.
00e0  78 39 42 90 0c 23 65 3d 3b 29 5f 95 c0 d7 cf 2c   x9B..#e=;)_….,
00f0  ae a5 0c 12 94 bc 41 bb 2e f1 33 05 2c 95 20 94   ……A…3.,. .
0100  3c 1f d6 32 9f 73 8b df 4c dc fe 5b cd 2a ac 3a   <..2.s..L..[.*.:

instead of something like

Lightweight-Directory-Access-Protocol
    LDAPMessage searchRequest(7) “DC=test,DC=loc” baseObject
        messageID: 7
        protocolOp: searchRequest (3)
            searchRequest
                baseObject: DC=test,DC=loc
                scope: baseObject (0)
                derefAliases: neverDerefAliases (0)
                sizeLimit: 0
                timeLimit: 120
                typesOnly: False
                Filter: (objectclass=*)
                    present: objectclass
                attributes: 1 item
                    Item: ntsecuritydescriptor
        [Response In: 72]
        controls: 2 items
            Item LDAP_SERVER_SD_FLAGS_OID
                controlType: 1.2.840.113556.1.4.801 (LDAP_SERVER_SD_FLAGS_OID)
                criticality: True
                controlValue: 308400000003020107
            Item LDAP_PAGED_RESULT_OID_STRING
                controlType: 1.2.840.113556.1.4.319 (LDAP_PAGED_RESULT_OID_STRING)
                criticality: True
                controlValue: 308400000006020203E80400

0000  00 a0 c9 ce b2 7b 00 50 8d 91 0b d2 08 00 45 00   …..{.P……E.
0010  00 e0 7a a7 40 00 80 06 fd 9b c0 a8 00 7a c0 a8   ..z.@……..z..
0020  00 0a 0b 74 01 85 f2 eb 1b 1d c0 25 e9 57 50 18   …t…….%.WP.
0030  f6 2e 82 a7 00 00 30 84 00 00 00 b2 02 01 07 63   ……0……..c
0040  84 00 00 00 48 04 0e 44 43 3d 74 65 73 74 2c 44   ….H..DC=test,D
0050  43 3d 6c 6f 63 0a 01 00 0a 01 00 02 01 00 02 01   C=loc………..
0060  78 01 01 00 87 0b 6f 62 6a 65 63 74 63 6c 61 73   x…..objectclas
0070  73 30 84 00 00 00 16 04 14 6e 74 73 65 63 75 72   s0…….ntsecur
0080  69 74 79 64 65 73 63 72 69 70 74 6f 72 a0 84 00   itydescriptor…
0090  00 00 5b 30 84 00 00 00 26 04 16 31 2e 32 2e 38   ..[0….&..1.2.8
00a0  34 30 2e 31 31 33 35 35 36 2e 31 2e 34 2e 38 30   40.113556.1.4.80
00b0  31 01 01 ff 04 09 30 84 00 00 00 03 02 01 07 30   1…..0……..0
00c0  84 00 00 00 29 04 16 31 2e 32 2e 38 34 30 2e 31   ….)..1.2.840.1
00d0  31 33 35 35 36 2e 31 2e 34 2e 33 31 39 01 01 ff   13556.1.4.319…
00e0  04 0c 30 84 00 00 00 06 02 02 03 e8 04 00         ..0………..

The second snippet clearly shows an LDAP query of

• Base DN: DC=test,DC=loc
• Scope: Base
• Filter: objectclass=*
• Return the attribute nTSecurityDescriptor…

The second is very clear and easy to understand. The first… Well not so easy.

This first capture looks the way it does due to a thing called LDAP Client Signing or LDAP Integrity. It “sort of” secures the data passing across LDAP. I say sort of because there are a few ways to get around it.

The first way around is to use the sysinternals tool called Insight for Active Directory. You can get that here… http://technet.microsoft.com/en-us/sysinternals/bb897539.aspx 

This is a pretty cool tool, can be very handy. You used to have to pay for it. But now you don’t. 🙂

 

The second way around is to disable the Client Signing. The current Client Signing setting is maintained in the registry (of course) in the key

hklm\system\currentcontrolset\services\ldap under the value ldapclientintegrity. There are three possible values

0	No signing/sealing
1	Negotiate signing/sealing
2	Require signing/sealing

You will likely see it set to 1 if it is set to anything. If it isn’t set, the default internally is 1 anyway… So if you switch this to 0, you will *generally* start seeing the LDAP traffic in the clear. If not, the issue could very well be that the application is forcing the information to be “encrypted” anyway like the AdFind -kerbenc switch does. At that point you have no choice but to use Insight for AD which hooks the LDAP calls prior to being encoded.

This can also be set through Group Policy so you may find that you set it to 0 and then later it goes back to 1 or even possibly 2. If that happens a GPO was configured to define a value for Computer Configuration | Windows Settings | Security Settings | Local Policies | Security Options | Network Security: LDAP client signing requirements.

     joe