Exchange 2010 ECP Performance Console

Introduction

Every Exchange Administrator has had at least one user complaining that Outlook or Outlook Web App [OWA] was running slow. Although most of the time this is due to the user’s PC or the network itself, sometimes there might be actually a performance issue with one or more Exchange servers. So the troubleshooting begins. We analyze how the CPU, memory and disk are performing through PerfMon, we look at the Event Logs, Exchange Best Practices Analyzer, we use Performance Troubleshooter, etc… But now there is another tool that might be useful in certain scenarios: the Exchange Control Panel [ECP] Performance Console.

This console, which is not visible by default, provides numerous counters regarding the performance of the ECP. We can use it to check how long it takes to authenticate a user, how many PowerShell cmdlets have been invoked and even how long the server took to process requests.

To enable it, we have to manually edit the web.config file on the Client Access Server [CAS] we want to troubleshoot or analyze. Outlook Web App and ECP both have a web.config file that is used to configure some settings specific to ASP.NET. In this case, we are only interested in the one for ECP, which is located (by default) in: %SystemDrive%\Program Files\Microsoft\Exchange Server\V14\ClientAccess\ecp\web.config

Open the file with Notepad and look for the <appSettings> section, right in the first few lines. In there we will find the following key:

<!– Set ShowPerformanceConsole to “true” to show ECP’s Perf Console: –>

<add key=”ShowPerformanceConsole” value=”false” />

As the comment explains, all we have to do to enable the console is update the value of the ShowPerformanceConsole key from false to true. Save the file, run the usual IISRESET /NOFORCE to update IIS and we are good to go!

If we log in to the ECP before this change and click on the drop-down to the right of the help icon, we will only see the Help, Help Bubble and Copyright links:

Figure 1

However, after enabling the console we will also have the Performance Console link:

Figure 2

Once we click on Performance Console, the console itself will open in a new window:

Figure 3

If we go straight to the console once we log in to ECP, we will only have the following URLs:

/ecp/

/ecp/PersonalSettings/HomePage.aspx

/ecp/PerfConsole.slab

But once we go back to ECP and start “moving around”, we will see information regarding more and more URLs as we can see from the screenshot above.

There are many counters available with this console, mostly are self-explanatory. Here is the list of all of them with a brief description:

• Request URL – the URL requested by the user;
• Client Request Time (ms) – the total time spent on the request, as measured by the client. This value ultimately measures the user perceived performance of the application;
• Server Request Time (ms) – the total time spent processing the request on the server. However, this does not include the network time to send or receive the request;
• RBAC Session – Number of RBAC sessions created during the request. A value of 1 indicates that a new session was created; a value of 0 means that a cached session was used;
• RBAC Session Latency (ms) – time spent creating an RBAC session during the request;
• RPC Requests – number of RPC operations executed during the request;
• RPC Latency (ms) – time spent in RPC operations during the request;
• LDAP Requests – number of LDAP operations executed during the request;
• LDAP Latency (ms) – time spent in LDAP operations during the request;
• Serialization – number of times Windows Communication Foundation [WCF] serialized or deserialized an object during the request;
• Serialization Time (ms) – time WCF spent serializing or deserializing objects during the request;
• Runspace – number of Windows PowerShell Runspaces created during this request. A value of 1 indicates that a new Runspace was created; a value of 0 means that a cached Runspace was used or not needed;
• Runspace Latency (ms) – time spent creating Windows PowerShell Runspaces in the request;
• Runspace Activations – number of times a Windows PowerShell Runspace was activated to run cmdlets;
• Runspace Active Time (ms) – the total time a Windows PowerShell Runspace was kept active during the request. This includes the time necessary to activate the Runspace, invoke and execute cmdlets, transform output objects and process errors;
• Windows PowerShell Invoke Count – number of times Windows PoerShell was invoked to run a cmdlet;
• Windows PowerShell Invoke Time (ms) – time spent running a cmdlet with Windows PowerShell. This includes the Cmdlet Time and time spent in the Windows PowerShell engine itself;
• Cmdlets Instantiated – number of Exchange cmdlets instantiated by this request. In certain situations this does not necessarily mean that the cmdlet was actually invoked;
• Cmdlet Time (ms) – time spent in Exchange cmdlet code. This includes time spent in the constructor, BeginProcessing, ProcessRecord and EndProcessing;
• Cmdlets Invoked – number of Exchange cmdlets effectively invoked by Windows PowerShell. This basically counts how many times BeginProcess was called in Exchange cmdlets;
• BeginProcessing Time (ms) – time spent running BeginProcessing in Exchange cmdlets;
• ProcessRecord Count – number of times ProcessRecord was called in Exchange cmdlets. This value indicates the number of input objects process by Exchange cmdlets during the request;
• Process Record Time (ms) – time spent running ProcessRecord in Exchange cmdlets. This usually includes most of the LDAP and RPC calls of the request;
• EndProcessing Time (ms) – time spent running EndProcessing in Exchange cmdlets;
• Authentication (ms) – time spent establishing the user identity of a request;
• Authorization (ms) – time spent authorizing the request. This includes creating RBAC sessions and initializing the Windows PowerShell Runspace configuration;
• Resolve Cache (ms) – time spent resolving the request with the server cache;
• Map Request (ms) – time spent mapping the request to the appropriate handler. This includes the time necessary for ASP.NET to load and compile markup files;
• Acquire State (ms) – time spent setting up the ASP.NET session for the request;
• Execute Handler (ms) – time spent processing the request with the appropriate handler. This includes processing pages and running cmdlets;
• Release State (ms) – time spent releasing the ASP.NET session of the request;
• Update Cache (ms) – time spent updating caching modules and storing responses that are used to serve subsequent requests from the cache;
• Log Request (ms) – time spent logging the request in the server;
• Client Network Time (ms) – time spent by the browser to send, wait and receive the response from the server;
• UI Response (ms) – time spent by the browser to process the response received. This value measures the performance of the client UI code.

Although most of these are too technical to be used by most administrators, there are many useful counters that will help troubleshoot a possible performance issue, such as Client Request Time, Server Request Time, LDAP Latency, Authentication or Client Network Time for example.

We can also export the table’s content by pressing the Copy button in the top left corner and copy all data into Notepad, Word, Excel, etc., which makes it easier to sort and analyze all counters:

Figure 4

But, there is more we can do with this console! In the <appSettings> section there is also another interesting feature:

<!– Set LogPerformanceData to “true” to log ECP’s performance records to the IIS log: –>

<add key=”LogPerformanceData” value=”false” />

By setting the LogPerformanceData to true, IIS will log all counters we see in the console for each request made to ECP. Let’s compare the same request (opening the InboxRules pane in ECP) without this setting enabled and with it enabled:

LogPerformanceData = False

2012-01-28 15:17:26 192.168.1.123 POST /ecp/RulesEditor/InboxRules.svc/GetList msExchEcpCanary=8ef6f537-6c83-43a8-ade4-9478fd4284e0 443 admin_nuno 192.168.1.126 Mozilla/4.0+(compatible;+MSIE+8.0;+Windows+NT+6.1;+WOW64;+Trident/4.0;+SLCC2;+.NET+CLR+2.0.50727;+.NET+CLR+3.5.30729;+.NET+CLR+3.0.30729) 200 0 0 875

LogPerformanceData = True

2012-01-28 15:28:17 192.168.1.123 POST /ecp/RulesEditor/InboxRules.svc/GetList msExchEcpCanary=82c1d465-f79b-428d-9d1a-cb5ba34141bdmsExchEcpCanary=82c1d465-f79b-428d-9d1a-cb5ba34141bd&perfRecord=%7b%22AcquireState%22%3a0.0293%2c%22ActiveRunspace%22%3a1%2c%22ActiveRunspaceLatency%22%3a193.3689%2c%22Authentication%22%3a0.2416%2c%22Authorization%22%3a2.676%2c%22BeginProcessing%22%3a1%2c%22BeginProcessingLatency%22%3a1.3202%2c%22Cmdlet%22%3a1%2c%22CmdletLatency%22%3a178.0984%2c%22CreateRunspace%22%3a0%2c%22CreateRunspaceLatency%22%3a0%2c%22EndProcessingLatency%22%3a0.0438%2c%22ExecuteRequest%22%3a637.305%2c%22Ldap%22%3a1%2c%22LdapLatency%22%3a0%2c%22LogRequest%22%3a0.0167%2c%22MapRequest%22%3a1.2071%2c%22PowerShellInvoke%22%3a1%2c%22PowerShellInvokeLatency%22%3a184.2382%2c%22ProcessRecord%22%3a1%2c%22ProcessRecordLatency%22%3a176.6232%2c%22Rbac%22%3a0%2c%22RbacLatency%22%3a0%2c%22ReleaseState%22%3a0.1262%2c%22ResolveCache%22%3a0.0505%2c%22Rpc%22%3a15%2c%22RpcLatency%22%3a31%2c%22ServerRequestTime%22%3a641.7921%2c%22UpdateCache%22%3a0.0396%2c%22WcfSerialization%22%3a2%2c%22WcfSerializationLatency%22%3a12.5355%7d 443 admin_nuno 192.168.1.126 Mozilla/4.0+(compatible;+MSIE+8.0;+Windows+NT+6.1;+WOW64;+Trident/4.0;+SLCC2;+.NET+CLR+2.0.50727;+.NET+CLR+3.5.30729;+.NET+CLR+3.0.30729) 200 0 0 843

As we can see, all counters present in the console are being logged into the IIS logs. It might not be easy to decipher all the values initially, but if we search for URL Encoding we will find that %22 is a quotation mark, %3a is a colon and %2c is a comma. With this in mind:

%22Rpc%22%3a15%2c%22RpcLatency%22%3a31

Becomes

“Rpc”:15,”RpcLatency”:31

With a good query using the famous Log Parser, we can easily analyze all these results for a specific user or even for all users, export the data to Excel and create a nice graph.

However, in my opinion, there are some downsides to this console:

1. It is specifically for ECP only. I looked for something similar for OWA but did not find anything;
2. It only logs data for the current user, unless we save all counters to the IIS log files. This means that if we open the console and we have more users using ECP on the same CAS server, we can only view data regarding our session. This might be an advantage or disadvantage, depending on how or who we would like to troubleshoot;
3. It is available for all users, not just administrators. Once we enable the console, everyone has access to it;
4. Once we login to ECP, the console starts to monitor all the URLs we visit, even if we don’t open the console. This might cause performance issues if we have hundreds of users using ECP.

Despite all of this, it is a useful tool if we are having performance issues and need some more detail on how ECP is performing.

I performed an online search for more details regarding this hidden feature but could not find any formal info from Microsoft. I only found two blog posts, including a great one from Steve Goodman who found this feature back in February 2010!

Other than this, the only thing I found was through the help icon in the console window, which takes us to the Outlook help webpage and where we can read the following:

The Performance Console is an internal Exchange team tool that displays performance information about network requests to the Exchange Control Panel server.

My guess is that this is just an internal tool, Microsoft has not yet made it public. As a final note, this feature is present in all versions of Exchange 2010, from RTM to SP2.

Summary

The hidden ECP Performance Console provides useful information regarding the performance of ECP for a specific CAS server. It is a valuable troubleshooting tool that should be also available for OWA.