The Raven Report

While troubleshooting excessive client login times, we identified an issue where the clients in one site would authenticate with DCs on the other side of the country.  

In our case a few of our sites are very well connected to our core site via high speed low latency links, so there are not any local DCs at site that users report slow logins.   

Initial test were inconclusive as a well connected DC was selected by the client, but we got lucky and one of our test system started experiencing the slow login issue.  After login set logonserver was run from the command line and a DC in the remote location with > 115ms latency was selected by this particular client PC.  At this point we were pretty sure the issue was in the AD site configuration, but did a couple more tests to confirm the suspicion.

We then repeatedly ran the following command multiple times to confirm our suspisions:

nltest /dsgetdc:domainname /force

The nltest command with the dsgetdc uses the same API the client does to select a DC.  In our case after multiple runs of the command DCs on the other side of the country were returned.

After notifying the directory services team of the issue it was determined that at the direction of an AD Consultant the site links between the core site and remote site were removed, and since no DCs were present on the site and the clients didn’t have enough information to determine the proper cost of a DC and were randomly selecting any DC in the environment. 

The AD team recreated the site links and the nltest  command  now only returns DCs in the core site.

Performance Analysis of Logs (PAL) is a nifty utility that will read in a performance counter log, analyze the data against customizable XML files with many built in counter thresholds, and then display the information in a HTML report.

You can find PAL Here:

http://www.codeplex.com/PAL

PAL only needs to be installed on the system that you are going to process the logs for not the System you are monitoring.  Go ahead download and install PAL and it’s prerequisites (Log Parser 2.2 & Microsoft Office Web Components 2003).  I wait till you’re done.

Now that PAL is installed we need to setup some Counter Logs on the system we want to analyze.  To do this go to Start then run and type Perfmon.  Go into Performance Logs and Alerts right-click Counter Logs and choose New Log Settings…

 

 

For a general system overview add the following counter objects:

LogicalDisk
Memory
Network Interface
PhysicalDisk
Process
Processor
System
TCPv4

Change the interval to something like 60 Seconds and click OK.

After saving the counter log settings, it should automatically start collecting data.  You can tell if it’s running because the icon will be green. 

Once the Counter Logs has been running for a sufficient amount of time go ahead and stop the logger.  At this point, you’ll want to copy the log file to the system that you installed PAL on.

Sidenote: 

PAL does come with VBScripts for creating these counters on the fly.  These are located C:\Program Files\PAL\PAL v1.3.4.2\PerfmonLogScripts .

Syntax:

cscript CreateAndStartPerfmonLogs.vbs <computer[;computer]> <ServerType> <CounterListFilePath>

<computer[;computer]>  List of computers to create and start the perfmon log.

<ServerType>           Text description to be added to the log name.

<CounterListFilePath>  File containing the list of perfmon counters.

Example:

Open a command window and change directory to C:\Program Files\PAL\PAL v1.3.4.2\PerfmonLogScripts.

cscript  CreateAndStartPerfmonLogs.vbs myserver sysoverview CounterList_SystemOverview.txt 

 

OK now back to Analyzing the Counter File:

Go ahead and open the PAL GUI and Click Next

On the Counter Log Screen you’ll want to browse out to the Log file we created earlier and click Next.

 

On the Threshold File screen Verify that the System Overview threshold file is selected. After and answering  the Question Variables Names  section in the lower left, Click Next.

 

Click Next to accept the defaults on the Analysis Interval screen:

 

Customize  the name and location of the output report on the Output Options Screen and click Next

 

 

The Queue Page displays the queued commands that the wizard has built Click Next to move to the final screen

 

 

 

On the Execute Screen verify Execute: Execute what is in the queue. is selected and choose Finish.

 

 

At this point PAL will kick off a VBScript that will slice and dice up the log file and generate a detailed report.  The report will highlight any thresholds that were exceeded, at the top of the report in the alerts section, and contains charts and suggested resolutions information for many of the counters analyzed. 

Seems like a simple thing, copying files from one system to another, but sometimes it’s the little things that make us think.

Case in point, a few years back we ran into an issue when copying many large (20GB+) files for one system to another. The system would actually run out of kernel memory after a couple of hours of copying the files and freeze up. A few tweaks and tests later we had found an acceptable number of concurrent processes and the copies went on without a hitch.

That was until recently, when the actual speed of the copy was brought into question.

Speed of the copy that’s fixed right? Not much we can do here outside of using robocopy or some third party tool, and even then we are still limited to by the fact that the transaction is buffered.  Buffered you say, what’s that?  Well in a Buffered transaction Windows keeps track of file reads and writes and buffers these transactions. Normally this works great speeding up future reads and writes to the files, but when dealing with large files the overhead of buffering can be staggering, not only in performance, but in kernel memory usage, hence the original problems with kernel pool exhaustion we experienced in the past.

Ok, so buffered transactions are slow down large file copies, how would we go about doing and unbuffered copy?  As far as I can tell there isn’t a native Windows tool that does un-buffered copy, but there is an Exchange tool ESEUTIL that can be used to accomplish this.  Just copy the ESEUTIL.EXE and ESE.DLL files from your friendly Microsoft Exchange system. The syntax for the command follows:

Eseutil /Y [Sourcefile] /D [Destinationfile]

One caveat with the Eseutil is that you can only do one file at a time and the utility does not accept wild cards so you’ll have to use the full path and file names when copying files.

So is it worth all this? You be the judge. In testing we had the following results for a 50GB  file copy  over a 1Gb connection:

Tool	Time
XCOPY	4 hours
3rd Party Tool	2.5 hours
ESEUTIL	35 Minutes

All in all not too shabby,  For more details  on this and other performance related issues check out  the Askperf Blog

Ok so now we know what to look for how to we look for it?

Tools

Task Manager

Task manager can quickly provide general memory information. On the performance tab, you can quickly determine how much physical memory is in the system, how much physical memory is available, Kernel memory usage and how much memory the VMM has promised to running processes. With this information you can determine if further investigation is required.

The processes tab also has a wealth of information, but first you have to enable additional columns via the View à Select Columns option. On this tab you can quickly determine the amount of memory a process is using and how much of the paged & nonpaged pool is being used.  There many addition columns available, so don’t settle for the default view.

Process Explorer

Process Explorer does everything task manager does and more. You can really dig into a process and figure exactly what it’s doing and what kind of resources it’s consuming.

Get it here:  http://technet.microsoft.com/en-us/sysinternals/bb896653.aspx

Poolmon

Poolmon is a great tool for tracking down kernel memory leaks or just determining what is consuming kernel resources .

More info here: http://support.microsoft.com/kb/177415  
& here: http://technet2.microsoft.com/windowsserver/en/library/0d302498-c947-4655-95af-719ae75acfb51033.mspx?mfr=true

Performance Counters

Memory\Available Mbytes (MB):  Indicates the amount of physical memory (in MB) immediately available for allocation to a process or for system use. Used with the Pages/Sec to determine if the system is low on physical memory.

Memory\Pages/sec: Pages/sec is the number of pages read from the disk or written to the disk to resolve memory references to pages that were not in memory at the time of the reference (hard page faults), and the number of pages that were redirected to memory outside of the working set.  This counter also includes paging traffic on behalf of the system Cache to access file data for applications, so a large number alone is not reason for concern just further investigation. This is the primary counter to observe if you are concerned about excessive memory thrashing.

Memory\Pool Nonpaged Bytes: This counter shows the current size of the Nonpaged pool in Bytes. Anything over 200MB should be investigated, and unless memory tuning options are in place (/3GB) then anything over 100MB.

Memory\Pool Paged Bytes: This counter shows the current size of the paged pool in Bytes. In general anything over ~250MB should be investigated unless memory tuning options are in place (/3GB) then anything over 150MB.

Memory\Free System Page Table Entries: This counter shows the number of page table entries that are available for use. Anything under 8,000 needs a closer look.  If the system is getting low consider using the /userva=XXXX with something like 3030 to start to bump these up.  

Memory: Cache Bytes: This is the size of the system cache. You can use this counter with the Pool nonpaged/paged & PTEs to determine who kernel memory is being allocated.

Registry Keys 

As with all registry modifications, use caution. Under normal circumstances you should not need  to modify these keys, but if you are running into kernel memory issues proper use of these keys can resolve the problem.

NonPagedPoolLimit: Specifies the maximum amount of system VA space that can be used by the nonpaged pool.

PagedPoolLimit: Specifies the maximum amount of system VA space that can be used by the paged pool.

SystemCacheLimit: Specifies the maximum amount of system VA space that can be used by the system cache.

SystemPtesLimit: Specifies the maximum amount of system VA space that can be used by I/O mappings and other resources that consume system page table entries (PTEs).

SessionSpaceLimit: Specifies the maximum amount of system VA space that can be used by session space allocations

PoolUsageMaximum: Determines the Max Poll usage before pruning starts.  The default is 80%. A value of 40-60 provides a workable solution to some paged pool exhaustion issues.

So that’s all the fun tools, counters and registry keys in a nutshell. In the next installment we’ll go over a real world example of isolating memory issues and providing workarounds.