Enable ROP logging in Exchange 2010 and 2013

  • Article

This is just a short post because it seems like there's not yet one on how to do it. https://www.expta.com/2012/07/how-to-enable-logging-for-rpc-client.html shows us how to enable throttling logging - and enabling ROP logging follows the same procedure. It is an additional logging tag that must be enabled inside the Microsoft.Exchange.RpcClientAccess.Service.exe.config file. Usually when I enable ROP logging, I enable throttling logging as well thus my config file would have this LoggingTag key:

<add key="LoggingTag" value="ConnectDisconnect, Logon, Failures, ApplicationData, Warnings, Throttling, Rops" />

Now when I open a log file, I'd see lines like this [I split this request using a comma delimiter so it's more legible]:

date-time,session-id,seq-number,client-name,organization-info,client-software,client-software-version,client-mode,client-ip,client-connection-info,server-ip,protocol,application-id,request-ids,session-cookie,operation,rpc-status,processing-time,operation-specific,failures,performance-data,activity-context-data,user-email

2014-09-18T15:32:28.583Z
83723
690
/o=Pulsarwinds/ou=Exchange Administrative Group (FYDIBOHF23SPDLT)/cn=Recipients/cn=MAHUYNH
OUTLOOK.EXE
14.0.7108.5000
Cached
ncacn_http
Client=MSExchangeRPC
0
00:00:00.0150000
" >SetProperties; >SetProperties; >SaveChangesMessage; >GetPropertiesSpecific; <SetProperties; <SetProperties; <SaveChangesMessage; <GetPropertiesSpecific; BS=Owner:Sid~Pulsarwinds\MAHUYNH~Rca~false
Conn:7
MaxConn:40
MaxBurst:150000
Balance:149980.5
Cutoff:Unlimited
RechargeRate:900000
Policy:GlobalThrottlingPolicy_09d51525-29c1-44b3-babc-4daaa4add881
IsServiceAccount:False
LiveTime:04:44:32.0860602"
mahuynh@pulsarwinds.com

Remote operation (ROP) logging allows you to see the ROPs that are sent from clients to the server and back. When you see a ROP that is prepended with '>', then it is being sent from the client. When you see a ROP that is prepended with '<', then it is being sent from the server. We can see that 4 ROPs were packed into this single request here.

RCA logs have a wealth of information. The client is connecting via Outlook 2010 cached mode using RPC over HTTP (Outlook Anywhere). We can also tell that he has 7 connections out of a maximum 40 used. His budget/balance is 149980.5ms so he's used up 19.5ms of server time globally across his connections. If the balance goes negative, the user will start encountering microdelays. Since there's no cutoff (it's unlimited), the user will never be denied/rejected outright via the RPC protocol.

Using the operation-specific field, you can extract the ROPs out and identify what a user's top ROPs are. My next blog post will have a script that does that and some info on how to generate basic stats on the extracted data.

Edit: Here's the promised script: https://blogs.technet.com/b/mahuynh/archive/2014/09/25/rop-breakdown-by-user.aspx