1

My code is working as expected. I'm really just curious to know if anyone has any idea why what I describe below might be happening. That said, if anyone has any ideas for further optimising the routine, I'd gratefully accept them in the spirit of every day being a school day!

The script is querying all our domain controllers to get the most recent lastLogon attribute for all users in a particular OU. (I am doing this instead of using the lastLogonTimeStamp attribute because I need the absolute most recent logon as of the moment the script is run.)

During testing, to check the code was doing what I expected it to do, I added some console output (included in the snippet below).

When I did this I noticed that with each iteration of the SECOND ForEach ( $DC in $AllDCs ) loop, there was a noticeable pause before the nested loop wrote its first line of console output. The duration of the pause increased with each iteration of the outer loop, and the speed of the inner loop's subsequent output also dropped noticeably. Over the course of the run, looking at the output of a dozen or so DCs, I'd estimate the rate console lines were being written dropped by at least a factor of 4.

$AllDCs = Get-ADDomainController -Filter *

$AllRecords = @{}

ForEach ( $DC in $AllDCs ) {

    $UserList = Get-ADUser -filter * -Server $DC -SearchBase $ini.OUDN.NewStartsInternal -SearchScope OneLevel -Properties lastLogon
    $UserList = $UserList | Where { $_.SamAccountName -match $ini.RegEx.PayNo }

    $AllRecords.Add($DC.Hostname,$UserList)

}

$Logons = @{}

ForEach ( $DC in $AllDCs ) {                                   ; this loop is the one I'm talking about
    
    ForEach ( $User in $AllRecords.$($DC.HostName) ) {

        If ( $Logons.ContainsKey($User.SamAccountName) ) {     ;this line amended on advice from mklement0
            
            If ( $Logons.$($User.SamAccountName) -lt $User.lastLogon ) {
            
                $Logons.$($User.SamAccountName) = $User.lastLogon
                Write-Host "Updated $($User.SamAccountName) to $($User.lastLogon)" -ForegroundColor Green

            } Else {

                Write-Host "Ignored $($User.SamAccountName)"

            }

        } Else {

            $Logons.Add( $User.SamAccountName , $User.lastLogon )

            Write-Host "Created $($User.SamAccountName)" -ForegroundColor Yellow

        }

    }

}

I'm not really any under any time constraints here as we're only talking a couple hundred users and a dozen or so domain controllers. I've already reduced the runtime by a huge amount anyway. Previously it was looping through the users and querying every DC for every user one by one which, unsurprisingly, was taking far longer.

UPDATE:

I implemented mklement0's suggestion from the first comment below, and if anything the script is actually running more slowly than before. The delays between iterations of the outer loop are longer, and the output from the inner loop seems subject to random delays. On average I'd say the inner loop is getting through about 2 to 3 iterations per second, which to my mind is extremely slow for looping through data that is already held in local memory. I know PowerShell has a reputation for being slow, but this seems exceptional.

The script normally runs on a VM so I tested it on my own computer and it was a LOT slower, so this isn't a resource issue with the VM.

UPDATE 2:

I removed all the Write-Host commands and simply timed each iteration of the outer loop.

First of all, removing all the console writes increased performance dramatically, which I expected, although I didn't realise by how much. It easily cut the run time to a fifth of what it had been.

In terms of the loop times, the strange behaviour is still there. Out of twelve iterations, the first seven are done within 1 second, and getting through the final five takes about 35 seconds. This behaviour repeats more or less the same every time. There is nothing different about the hostnames of the final five DCs compared to the first seven that may be slowing down the hashtable lookup.

I'm very happy with the run time as it is now, but still utterly perplexed about this weird behaviour.

Improve this question
11
  • 5
    The only obvious slowdown comes from $Logons.Keys -contains $User.SamAccountName, because you're performing a linear lookup in a (growing) array; use $Logons.ContainsKey($User.SamAccountName) instead. Commented Aug 11, 2021 at 2:14
  • 1
    I'm wondering, are you hitting that else statement after your first iteration, just out of curiosity. Ways you could make this run faster that I could think of, you can use Runspaces or Start-ThreadJob or the even faster solution would be Invoke-Command to all Domain Controllers at the same time. Commented Aug 11, 2021 at 2:16
  • 1
    To add to the other helpful comments, switching the order of the expression $User.SamAccountName -in $Logons.Keys has a performance increase. Seeing as the -in operator looks for the single value and stops at that, whereas -contains looks at the entirety of the container before stopping/continuing. This is just an aside tip. Stick to Mkelements suggestion.of $Logons.ContainsKey($User.SamAccountName), and Santiago's advice. Commented Aug 11, 2021 at 2:40
  • 1
    By the way, I might be wrong but, shouldn't $AllRecords.Add($DC,$UserList) be $AllRecords.Add($DC.sAMAccountName,$UserList) or $AllRecords.Add($DC.DistinguishedName,$UserList) ? Your Hashtable Keys are ADDomainController objects instead of strings I think. Commented Aug 11, 2021 at 3:39
  • 1
    @mklement0 - the array isn't actually growing after the first outer loop but I will implement that anyway cheers +1 Commented Aug 11, 2021 at 8:04

1 Answer 1

Reset to default
1

So, this is my take on your code, I didn't change many things but I have a feeling this should be a bit faster but I may be wrong.

Note, I'm using LDAPFilter = '(LastLogon=*)' instead of Filter = '*' because, if it's an attribute that is not replicated across the domain it will save time when querying each Domain Controller.

$AllDCs = Get-ADDomainController -Filter *
$logons = @{}

$params = @{
    LDAPFilter  = '(LastLogon=*)'
    Server      = ''
    SearchBase  = $ini.OUDN.NewStartsInternal
    SearchScope = 'OneLevel'
    Properties  = 'lastLogon'
}

foreach($DC in $AllDCs) {
    $params.Server = $DC
    $UserList = Get-ADUser @params
    
    foreach($user in $UserList) {
        if($user.samAccountName -notmatch $ini.RegEx.PayNo) {
            continue
        }

        if($logons[$user.samAccountName].LastLogon -lt $user.LastLogon) {
            # On first loop iteration should be always entering
            # this condition because
            # $null -lt [datetime]::MaxValue => True AND
            # $null -lt [datetime]::MinValue => True
            # Assuming $user.LastLogon is always a populated attribute
            # which also explains my LDAPFilter = '(LastLogon=*)' from before

            $logons[$user.samAccountName] = $user
        }
    }
}
Improve this answer
Sign up to request clarification or add additional context in comments.

4 Comments

Apologies for delay in responding - been a busy on-call week so just getting back to it now. Completely see the sense in doing it this way; I will try it out today.
Worked a treat thanks. ~30 secs to complete vs ~90 secs previously. Very handy given this is part of a larger job that runs every five minutes.
Still puzzled as to what may have been causing the slowdown previously, given all necessary data was in RAM when the slowdown was happening, but I am content not to worry about that now.
@blackworx I can tell your script should be consuming more RAM but I don't think that's the reason for slowing down on each iteration. I honestly dont know.

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Start asking to get answers

Find the answer to your question by asking.

Ask question

Explore related questions

See similar questions with these tags.