Hi,

I have a load balanced, virtualized windows authenticated sharepoint 2010 farm. I also have a similar setup on another farm.

Now the issue is that about the first load page load performance issue after am IISRESET. In fact both the Farms are slow for the first load. Farm1 takes only 15 seconds whereas my Farm2 takes 90+ seconds to render the same page. I agree that its normal to take 15 seconds during first load but 90+ seconds!?



I copy paste here what I mean by it (taken from the developer dashboard enabled):



Page Load after an IISRESET

Request (GET:http://sp.comp.com:80/sites/def/Pages/Home.aspx) (91795.54 ms)
BeginRequestHandler (0.30 ms)
PostAuthenticateRequestHandler (0.09 ms)
PostResolveRequestCacheHandler (70840.73 ms)
ExecuteOnChannel:GetProfileProperties (57873.59 ms)
CreateChannelAsProcess:Microsoft.Office.Server.UserProfiles.IProfilePropertyService (57208.08 ms)
GetProcessSecurityTokenForServiceContext (57200.28 ms)
CreateChannelWithIssuedToken (6.67 ms)
InitializeWcfOperation (0.10 ms)
ExecuteWcfOperation:Microsoft.Office.Server.UserProfiles/GetProfileProperties (83.99 ms)
CleanUpWcfOperation (0.02 ms)
GetWebPartPageContent (4401.46 ms)
GetFileAndMetaInfo (4397.77 ms)
Proxy Channel call for Enterprise Metadata Service (1131.88 ms)




Subsequent Page Load of the same page

Request (GET: http://sp.comp.com:80/sites/def/Pages/Home.aspx) (930.62 ms)
BeginRequestHandler (0.11 ms)
PostAuthenticateRequestHandler (0.09 ms)
PostResolveRequestCacheHandler (84.69 ms)
GetWebPartPageContent (79.86 ms)
GetFileAndMetaInfo (77.24 ms)
PortalSiteMapDataSource: Determining Starting Node (0.05 ms)
PortalSiteMapDataSource: Determining Starting Node#1 (0.02 ms)
Add WebParts (10.82 ms)
CompUserPreferenceWebPart (0.89 ms)
Newsbytes (3.18 ms)
Comp Home (3.21 ms)


Findings so far:
I found that if I were to uncheck the User Profile Service & the Metadata Service from this page’s associated web app, the first load is much faster - about 20 seconds.
I’ve also verified disabling the antivirus checking on all servers.


Some other significant entries that I noticed from the Logs are:

0x0EE8 SharePoint Foundation Monitoring b4ly Verbose Leaving Monitored Scope (GetProcessSecurityTokenForServiceContext). Execution Time=57510.6440902405



I also noticed another entry, which helped me rule out the possibility of any wait for certificate validation:

SharePoint Foundation Monitoring b4ly Verbose Leaving Monitored Scope (SPCertificateValidator.Validate). Execution Time=10.3105282934004



Another entry I noticed which I’ve no idea is about (since I use windows auth):

Monitored Scope (SPClaimProviderOperations.ClaimsForEntity()). Execution Time=22051.8979367489



Any ideas on the purpose or function of GetProcessSecurityTokenForServiceContext ? Does it relate to the User profile service and the Metadata Service. What about SPClaimProviderOperations.ClaimsForEntity



Thanks,


Kind Regards,
Jai