Slow re-loading of pages

Nov 23, 2010 at 12:39 AM

Hi,

Similar to IGROK and his posting about the loading speed of the portal...

The documentation states that website caching is enabled for performance, however the load speed (when it comes to re-loading pages) doesn't back this up.

  • Our CRM database is about 18Gb in size
  • The PRM portal has been configured to use AD authentication as per Shan MsArthur's post (website appears to be down at present).
  • Portal basically works
  • Re-loading each page (when using F5 in a browser) takes about 20-30 sec !!

Has anyone experienced the same portal loading speed issues? What can I do to improve this speed? Does output caching need to be configured?

Thanks,

S

Nov 23, 2010 at 3:17 PM

The original post is about the startup delay (initial load speed), and there is nothing that can be done with that.  However, once the portal is running (and assuming you don't have IIS configured to shut it down in 20 minutes), subsequent page results are retrieved from cache and are very fast.  I would not expect that reloading of the page would take 20 seconds- 20 milliseconds would be more appropriate.  I would check for other infrastructure issues such as insufficient memory in your asp.net web page.  To give you some perspective, our own corporate website is running on this and we do not have a performance issue (www.adxstudio.com).  another useful thing is to look at the asp.net trace.

Shan

Nov 24, 2010 at 9:00 PM

Shan,

Thanks for your reply. We've used asp tracing and I can now confirm the following loading times:

  • Channel page                                                16 seconds when loaded from cache
  • My Opportunities                                          20 seconds when loaded from cache
  • Service page                                                 12 seconds when loaded from cache
  • Create opportunity (after pressing continue)    13 seconds when loaded from cache

As you see we experience seconds not milliseconds.

Trace files below fyi. Any help is appreciated.

Thanks,
S

Channel page 16 seconds when loaded from cache

       
Category Message From First(s) From Last(s)
Microsoft.Xrm.Portal.Web.SiteContextModule Request URL = http://192.168.129.3:81/Default.aspx?404;http://192.168.129.3:81/channel; clientUrl=http://192.168.129.3:81/channel

EmbeddedResourceVirtualPathProvider: FileExists virtualPath=/channel, exists=False 0.0001483 0.000148
Microsoft.Xrm.Portal.Web.CrmSiteMapProvider FindSiteMapNode(/channel) 0.0077161 0.007568
Microsoft.Xrm.Portal.Web.SiteContextModule Rewriting path to /Pages/Page.aspx?pageid=6c69c125-a08a-469e-8b71-09c640c35755 0.0087758 0.00106
aspx.page Begin PreInit 0.0093567 0.000581
Microsoft.Xrm.Portal.Web.CrmSiteMapProvider FindSiteMapNode(/channel) 0.0096383 0.000282
aspx.page End PreInit 0.0188612 0.009223
aspx.page Begin Init 0.0188883 0.000027
aspx.page End Init 0.0189565 0.000068
aspx.page Begin InitComplete 0.0189699 0.000013
aspx.page End InitComplete 0.0189808 0.000011
aspx.page Begin PreLoad 0.018991 0.00001
aspx.page End PreLoad 0.0190092 0.000018
aspx.page Begin Load 0.0190197 0.000011
CrmQueryProvider: Execute Begin: TElement=Microsoft.Xrm.Client.ICrmEntity 0.0235508 0.004531
CrmQueryProvider: Execute EntityName=contact 0.0253347 0.001784
CrmQueryProvider: Execute End: duration: 3 ms 0.0268985 0.001564
Microsoft.Xrm.Portal.Web.CrmSiteMapProvider FindSiteMapNode(/channel) 0.0551488 0.02825
Microsoft.Xrm.Portal.Web.CrmSiteMapProvider FindSiteMapNode(/channel) 0.0568794 0.001731
Microsoft.Xrm.Portal.Web.CrmSiteMapProvider FindSiteMapNode(/channel) 0.060057 0.003178
Microsoft.Xrm.Portal.Web.CrmSiteMapProvider GetChildNodes(/channel) 0.0625543 0.002497
aspx.page End Load 0.099973 0.037419
aspx.page Begin LoadComplete 0.1000055 0.000033
aspx.page End LoadComplete 0.1000169 0.000011
aspx.page Begin PreRender 0.1000272 0.00001
Microsoft.Xrm.Portal.Web.CrmSiteMapProvider FindSiteMapNode(/profile) 0.1023201 0.002293
Microsoft.Xrm.Portal.Web.CrmSiteMapProvider FindSiteMapNode(/channel) 0.1093418 0.007022
Microsoft.Xrm.Portal.Web.CrmSiteMapProvider GetParentNode(/channel) 0.1105116 0.00117
Microsoft.Xrm.Portal.Web.CrmSiteMapProvider GetParentNode(/) 0.1115557 0.001044
Microsoft.Xrm.Portal.Web.CrmSiteMapProvider FindSiteMapNode(/channel) 0.1213887 0.009833
aspx.page End PreRender 0.1243391 0.00295
aspx.page Begin PreRenderComplete 0.1243619 0.000023
aspx.page End PreRenderComplete 0.1244292 0.000067
aspx.page Begin SaveState 0.1461373 0.021708
aspx.page End SaveState 0.1464837 0.000346
aspx.page Begin SaveStateComplete 0.1465001 0.000016
aspx.page End SaveStateComplete 0.1465131 0.000013
aspx.page Begin Render 0.1465234 0.00001
CrmQueryProvider: Execute Begin: TElement=Microsoft.Xrm.Client.ICrmEntity 0.1475988 0.001075
CrmQueryProvider: Execute EntityName=contact 0.1501266 0.002528
CrmQueryProvider: Execute End: duration: 5 ms 0.1526487 0.002522
aspx.page End Render 0.1570772 0.004429
       








My Opportunities 20 seconds when loaded from cache





Category Message From First(s) From Last(s)
Microsoft.Xrm.Portal.Web.SiteContextModule Request URL = http://192.168.129.3:81/Default.aspx?404;http://192.168.129.3:81/channel/approved-deals; clientUrl=http://192.168.129.3:81/channel/approved-deals

EmbeddedResourceVirtualPathProvider: FileExists virtualPath=/channel/approved-deals, exists=False 0.0001443 0.000144
Microsoft.Xrm.Portal.Web.CrmSiteMapProvider FindSiteMapNode(/channel/approved-deals) 0.0020448 0.001901
Microsoft.Xrm.Portal.Web.SiteContextModule Rewriting path to /Pages/MyOpportunities.aspx?pageid=958b04ed-5965-4778-b52c-145abdee97f8 0.0030213 0.000977
aspx.page Begin PreInit 0.0035189 0.000498
Microsoft.Xrm.Portal.Web.CrmSiteMapProvider FindSiteMapNode(/channel/approved-deals) 0.0037939 0.000275
aspx.page End PreInit 0.0127614 0.008968
aspx.page Begin Init 0.0127817 0.00002
aspx.page End Init 0.01285 0.000068
aspx.page Begin InitComplete 0.0128637 0.000014
aspx.page End InitComplete 0.0128747 0.000011
aspx.page Begin PreLoad 0.0128849 0.00001
aspx.page End PreLoad 0.012905 0.00002
aspx.page Begin Load 0.0129155 0.000011
CrmQueryProvider: Execute Begin: TElement=Microsoft.Xrm.Client.ICrmEntity 0.0132106 0.000295
CrmQueryProvider: Execute EntityName=contact 0.0144115 0.001201
CrmQueryProvider: Execute End: duration: 2 ms 0.0157035 0.001292
CrmQueryProvider: Execute Begin: TElement=Microsoft.Xrm.Client.ICrmEntity 0.0159538 0.00025
CrmQueryProvider: Execute EntityName=adx_opportunityaccess 0.0159889 0.000035
CrmQueryProvider: Execute End: duration: 1 ms 0.0170893 0.0011
CrmQueryProvider: Execute Begin: TElement=Microsoft.Xrm.Client.ICrmEntity 0.0176006 0.000511
CrmQueryProvider: Execute EntityName=contact 0.0186502 0.00105
CrmQueryProvider: Execute End: duration: 2 ms 0.0198496 0.001199
CrmQueryProvider: Execute Begin: TElement=Microsoft.Xrm.Client.ICrmEntity 0.0199906 0.000141
CrmQueryProvider: Execute EntityName=adx_opportunityaccess 0.0200248 0.000034
CrmQueryProvider: Execute End: duration: 1 ms 0.0210773 0.001053
CrmQueryProvider: Execute Begin: TElement=Microsoft.Xrm.Client.ICrmEntity 0.0214762 0.000399
CrmQueryProvider: Execute EntityName=contact 0.0233452 0.001869
CrmQueryProvider: Execute End: duration: 3 ms 0.0245196 0.001174
CrmQueryProvider: Execute Begin: TElement=Microsoft.Xrm.Client.ICrmEntity 0.0251078 0.000588
CrmQueryProvider: Execute EntityName=contact 0.0262002 0.001092
CrmQueryProvider: Execute End: duration: 2 ms 0.0274062 0.001206
CrmQueryProvider: Execute Begin: TElement=Microsoft.Xrm.Client.ICrmEntity 0.0275489 0.000143
CrmQueryProvider: Execute EntityName=adx_opportunityaccess 0.0275851 0.000036
CrmQueryProvider: Execute End: duration: 1 ms 0.028641 0.001056
CrmQueryProvider: Execute Begin: TElement=Microsoft.Xrm.Client.ICrmEntity 0.0290883 0.000447
CrmQueryProvider: Execute EntityName=contact 0.0301098 0.001022
CrmQueryProvider: Execute End: duration: 2 ms 0.031314 0.001204
CrmQueryProvider: Execute Begin: TElement=Microsoft.Xrm.Client.ICrmEntity 0.0314547 0.000141
CrmQueryProvider: Execute EntityName=adx_opportunityaccess 0.0314906 0.000036
CrmQueryProvider: Execute End: duration: 1 ms 0.0325483 0.001058
CrmQueryProvider: Execute Begin: TElement=Microsoft.Xrm.Client.ICrmEntity 0.0329461 0.000398
CrmQueryProvider: Execute EntityName=contact 0.0339879 0.001042
CrmQueryProvider: Execute End: duration: 2 ms 0.0351664 0.001179
CrmQueryProvider: Execute Begin: TElement=Microsoft.Xrm.Client.ICrmEntity 0.0356209 0.000455
CrmQueryProvider: Execute EntityName=contact 0.0366443 0.001023
CrmQueryProvider: Execute End: duration: 2 ms 0.0378428 0.001199
CrmQueryProvider: Execute Begin: TElement=Microsoft.Xrm.Client.ICrmEntity 0.0379857 0.000143
CrmQueryProvider: Execute EntityName=adx_opportunityaccess 0.0380205 0.000035
CrmQueryProvider: Execute End: duration: 1 ms 0.039076 0.001056
CrmQueryProvider: Execute Begin: TElement=Microsoft.Xrm.Client.ICrmEntity 0.0395192 0.000443
CrmQueryProvider: Execute EntityName=contact 0.0405642 0.001045
CrmQueryProvider: Execute End: duration: 3 ms 0.0434203 0.002856
CrmQueryProvider: Execute Begin: TElement=Microsoft.Xrm.Client.ICrmEntity 0.0435714 0.000151
CrmQueryProvider: Execute EntityName=adx_opportunityaccess 0.0436084 0.000037
CrmQueryProvider: Execute End: duration: 1 ms 0.0446705 0.001062
CrmQueryProvider: Execute Begin: TElement=Xrm.savedquery 0.0499927 0.005322
CrmQueryProvider: Execute EntityName=savedquery 0.0502046 0.000212
CrmQueryProvider: Execute End: duration: 1 ms 0.0513624 0.001158
CrmQueryProvider: Execute Begin: TElement=Microsoft.Xrm.Client.ICrmEntity 0.0517319 0.00037
CrmQueryProvider: Execute EntityName=contact 0.0527903 0.001058
CrmQueryProvider: Execute End: duration: 2 ms 0.0539895 0.001199
CrmQueryProvider: Execute Begin: TElement=Microsoft.Xrm.Client.ICrmEntity 0.0541311 0.000142
CrmQueryProvider: Execute EntityName=adx_opportunityaccess 0.0541673 0.000036
CrmQueryProvider: Execute End: duration: 1 ms 0.055225 0.001058
CrmQueryProvider: Execute Begin: TElement=Microsoft.Xrm.Client.ICrmEntity 0.0556694 0.000444
CrmQueryProvider: Execute EntityName=contact 0.0567218 0.001052
CrmQueryProvider: Execute End: duration: 2 ms 0.0586064 0.001885
CrmQueryProvider: Execute Begin: TElement=Microsoft.Xrm.Client.ICrmEntity 0.0587576 0.000151
CrmQueryProvider: Execute EntityName=adx_opportunityaccess 0.0587965 0.000039
CrmQueryProvider: Execute End: duration: 1 ms 0.0598547 0.001058
CrmQueryProvider: Execute Begin: TElement=System.Int32 0.060221 0.000366
CrmQueryProvider: Execute EntityName=opportunity 0.065499 0.005278
CrmQueryProvider: Execute End: duration: 7 ms 0.0677304 0.002231
CrmQueryProvider: Execute Begin: TElement=Microsoft.Xrm.Client.ICrmEntity 0.0678609 0.000131
CrmQueryProvider: Execute EntityName=opportunity 0.0729609 0.0051
CrmQueryProvider: Execute End: duration: 22 ms 0.0905758 0.017615
CrmQueryProvider: Execute Begin: TElement=Microsoft.Xrm.Client.ICrmEntity 0.0912943 0.000719
CrmQueryProvider: Execute EntityName=opportunity 0.0965195 0.005225
CrmQueryProvider: Execute End: duration: 20 ms 0.1122012 0.015682
CrmQueryProvider: Execute Begin: TElement=Microsoft.Xrm.Client.ICrmEntity 0.1157304 0.003529
CrmQueryProvider: Execute EntityName=opportunity 0.1213487 0.005618
CrmQueryProvider: Execute End: duration: 7 ms 0.1232245 0.001876
CrmQueryProvider: Execute Begin: TElement=Microsoft.Xrm.Client.ICrmEntity 0.1241336 0.000909
CrmQueryProvider: Execute EntityName=savedquery 0.1252274 0.001094
CrmQueryProvider: Execute End: duration: 2 ms 0.1264207 0.001193
CrmQueryProvider: Execute Begin: TElement=Microsoft.Xrm.Client.ICrmEntity 0.131314 0.004893
CrmQueryProvider: Execute EntityName=contact 0.1329531 0.001639
CrmQueryProvider: Execute End: duration: 2 ms 0.1342363 0.001283
aspx.page End Load 0.1687941 0.034558
aspx.page Begin LoadComplete 0.1688281 0.000034
aspx.page End LoadComplete 0.1688396 0.000012
aspx.page Begin PreRender 0.1688498 0.00001
Microsoft.Xrm.Portal.Web.CrmSiteMapProvider FindSiteMapNode(/profile) 0.1711352 0.002285
Microsoft.Xrm.Portal.Web.CrmSiteMapProvider FindSiteMapNode(/channel/approved-deals) 0.1782202 0.007085
Microsoft.Xrm.Portal.Web.CrmSiteMapProvider GetParentNode(/channel/approved-deals) 0.179393 0.001173
Microsoft.Xrm.Portal.Web.CrmSiteMapProvider GetParentNode(/channel) 0.1804373 0.001044
Microsoft.Xrm.Portal.Web.CrmSiteMapProvider GetParentNode(/) 0.1814804 0.001043
Microsoft.Xrm.Portal.Web.CrmSiteMapProvider FindSiteMapNode(/channel/approved-deals) 0.1905554 0.009075
aspx.page End PreRender 0.1934706 0.002915
aspx.page Begin PreRenderComplete 0.1934919 0.000021
aspx.page End PreRenderComplete 0.193551 0.000059
aspx.page Begin SaveState 0.1966948 0.003144
aspx.page End SaveState 0.1970466 0.000352
aspx.page Begin SaveStateComplete 0.197064 0.000017
aspx.page End SaveStateComplete 0.1970749 0.000011
aspx.page Begin Render 0.1970851 0.00001
CrmQueryProvider: Execute Begin: TElement=Microsoft.Xrm.Client.ICrmEntity 0.1990904 0.002005
CrmQueryProvider: Execute EntityName=contact 0.2003477 0.001257
CrmQueryProvider: Execute End: duration: 2 ms 0.2017658 0.001418
aspx.page End Render 0.203967 0.002201








Service 12 seconds when loaded from cache





Category Message From First(s) From Last(s)
Microsoft.Xrm.Portal.Web.SiteContextModule Request URL = http://192.168.129.3:81/Default.aspx?404;http://192.168.129.3:81/support; clientUrl=http://192.168.129.3:81/support

EmbeddedResourceVirtualPathProvider: FileExists virtualPath=/support, exists=False 0.0001379 0.000138
Microsoft.Xrm.Portal.Web.CrmSiteMapProvider FindSiteMapNode(/support) 0.0081669 0.008029
Microsoft.Xrm.Portal.Web.SiteContextModule Rewriting path to /Pages/Page.aspx?pageid=6129b1cc-f866-4f57-a3a7-b366da895a4b 0.0092078 0.001041
aspx.page Begin PreInit 0.0098261 0.000618
Microsoft.Xrm.Portal.Web.CrmSiteMapProvider FindSiteMapNode(/support) 0.0101079 0.000282
aspx.page End PreInit 0.0193529 0.009245
aspx.page Begin Init 0.019375 0.000022
aspx.page End Init 0.0194423 0.000067
aspx.page Begin InitComplete 0.0194558 0.000014
aspx.page End InitComplete 0.0194667 0.000011
aspx.page Begin PreLoad 0.0194769 0.00001
aspx.page End PreLoad 0.019497 0.00002
aspx.page Begin Load 0.0195077 0.000011
CrmQueryProvider: Execute Begin: TElement=Microsoft.Xrm.Client.ICrmEntity 0.0225727 0.003065
CrmQueryProvider: Execute EntityName=contact 0.0245724 0.002
CrmQueryProvider: Execute End: duration: 3 ms 0.0260309 0.001459
Microsoft.Xrm.Portal.Web.CrmSiteMapProvider FindSiteMapNode(/support) 0.0405685 0.014538
Microsoft.Xrm.Portal.Web.CrmSiteMapProvider FindSiteMapNode(/support) 0.0418409 0.001272
Microsoft.Xrm.Portal.Web.CrmSiteMapProvider FindSiteMapNode(/support) 0.0447112 0.00287
Microsoft.Xrm.Portal.Web.CrmSiteMapProvider GetChildNodes(/support) 0.0462692 0.001558
aspx.page End Load 0.0767423 0.030473
aspx.page Begin LoadComplete 0.0767776 0.000035
aspx.page End LoadComplete 0.0767891 0.000012
aspx.page Begin PreRender 0.0768024 0.000013
Microsoft.Xrm.Portal.Web.CrmSiteMapProvider FindSiteMapNode(/profile) 0.0798383 0.003036
Microsoft.Xrm.Portal.Web.CrmSiteMapProvider FindSiteMapNode(/support) 0.0890707 0.009232
Microsoft.Xrm.Portal.Web.CrmSiteMapProvider GetParentNode(/support) 0.0902607 0.00119
Microsoft.Xrm.Portal.Web.CrmSiteMapProvider GetParentNode(/) 0.091308 0.001047
Microsoft.Xrm.Portal.Web.CrmSiteMapProvider FindSiteMapNode(/support) 0.0983656 0.007058
aspx.page End PreRender 0.1013008 0.002935
aspx.page Begin PreRenderComplete 0.1013212 0.00002
aspx.page End PreRenderComplete 0.1013903 0.000069
aspx.page Begin SaveState 0.1042698 0.00288
aspx.page End SaveState 0.1045725 0.000303
aspx.page Begin SaveStateComplete 0.1045912 0.000019
aspx.page End SaveStateComplete 0.1046024 0.000011
aspx.page Begin Render 0.1046125 0.00001
CrmQueryProvider: Execute Begin: TElement=Microsoft.Xrm.Client.ICrmEntity 0.1054438 0.000831
CrmQueryProvider: Execute EntityName=contact 0.1067143 0.001271
CrmQueryProvider: Execute End: duration: 2 ms 0.1081324 0.001418
aspx.page End Render 0.1180952 0.009963








Create opportunity (after pressing continue) 13 seconds when loaded from cache





Category Message From First(s) From Last(s)
Microsoft.Xrm.Portal.Web.SiteContextModule Request URL = http://192.168.129.3:81/Default.aspx?404;http://192.168.129.3:81/channel/register-deal; clientUrl=http://192.168.129.3:81/channel/register-deal

EmbeddedResourceVirtualPathProvider: FileExists virtualPath=/channel/register-deal, exists=False 0.0001505 0.000151
Microsoft.Xrm.Portal.Web.CrmSiteMapProvider FindSiteMapNode(/channel/register-deal) 0.0021463 0.001996
Microsoft.Xrm.Portal.Web.SiteContextModule Rewriting path to /Pages/CreateOpportunity.aspx?pageid=7fbb7f44-a9e7-df11-93fc-00155d80290c 0.0031764 0.00103
aspx.page Begin PreInit 0.0037923 0.000616
Microsoft.Xrm.Portal.Web.CrmSiteMapProvider FindSiteMapNode(/channel/register-deal) 0.0048982 0.001106
aspx.page End PreInit 0.0140294 0.009131
aspx.page Begin Init 0.0140508 0.000021
aspx.page End Init 0.0142459 0.000195
aspx.page Begin InitComplete 0.0142647 0.000019
aspx.page End InitComplete 0.0142764 0.000012
aspx.page Begin PreLoad 0.0142865 0.00001
aspx.page End PreLoad 0.0143072 0.000021
aspx.page Begin Load 0.0143177 0.000011
CrmQueryProvider: Execute Begin: TElement=Microsoft.Xrm.Client.ICrmEntity 0.01462 0.000302
CrmQueryProvider: Execute EntityName=contact 0.0159935 0.001374
CrmQueryProvider: Execute End: duration: 2 ms 0.0174172 0.001424
CrmQueryProvider: Execute Begin: TElement=Microsoft.Xrm.Client.ICrmEntity 0.0177906 0.000373
CrmQueryProvider: Execute EntityName=adx_opportunityaccess 0.0178253 0.000035
CrmQueryProvider: Execute End: duration: 4 ms 0.0221565 0.004331
CrmQueryProvider: Execute Begin: TElement=Microsoft.Xrm.Client.ICrmEntity 0.0229889 0.000832
CrmQueryProvider: Execute EntityName=contact 0.0243193 0.00133
CrmQueryProvider: Execute End: duration: 2 ms 0.0255231 0.001204
CrmQueryProvider: Execute Begin: TElement=Microsoft.Xrm.Client.ICrmEntity 0.0257604 0.000237
CrmQueryProvider: Execute EntityName=adx_opportunityaccess 0.0257951 0.000035
CrmQueryProvider: Execute End: duration: 1 ms 0.0268604 0.001065
CrmQueryProvider: Execute Begin: TElement=Microsoft.Xrm.Client.ICrmEntity 0.030375 0.003515
CrmQueryProvider: Execute EntityName=contact 0.0334228 0.003048
CrmQueryProvider: Execute End: duration: 4 ms 0.0347146 0.001292
aspx.page End Load 0.07015 0.035435
aspx.page Begin LoadComplete 0.0701832 0.000033
aspx.page End LoadComplete 0.070195 0.000012
aspx.page Begin PreRender 0.070208 0.000013
Microsoft.Xrm.Portal.Web.CrmSiteMapProvider FindSiteMapNode(/profile) 0.0725212 0.002313
Microsoft.Xrm.Portal.Web.CrmSiteMapProvider FindSiteMapNode(/channel/register-deal) 0.0796442 0.007123
Microsoft.Xrm.Portal.Web.CrmSiteMapProvider GetParentNode(/channel/register-deal) 0.0808228 0.001179
Microsoft.Xrm.Portal.Web.CrmSiteMapProvider GetParentNode(/channel) 0.0818712 0.001048
Microsoft.Xrm.Portal.Web.CrmSiteMapProvider GetParentNode(/) 0.0862196 0.004348
CrmDataSourceView: BeginExecuteSelect Begin 0.1060985 0.019879
CrmDataSourceView: BeginExecuteSelect CancelSelectOnNullParameter 0.1061472 0.000049
CrmDataSourceView: EndExecuteSelect Begin 0.1061613 0.000014
CrmDataSourceView: EndExecuteSelect End: _client=null 0.1061728 0.000012
Microsoft.Xrm.Portal.Web.CrmSiteMapProvider FindSiteMapNode(/channel/register-deal) 0.1099129 0.00374
aspx.page End PreRender 0.1128787 0.002966
aspx.page Begin PreRenderComplete 0.1128989 0.00002
aspx.page End PreRenderComplete 0.1129438 0.000045
aspx.page Begin SaveState 0.1211463 0.008203
aspx.page End SaveState 0.1218687 0.000722
aspx.page Begin SaveStateComplete 0.1218878 0.000019
aspx.page End SaveStateComplete 0.1218986 0.000011
aspx.page Begin Render 0.121909 0.00001
CrmQueryProvider: Execute Begin: TElement=Microsoft.Xrm.Client.ICrmEntity 0.1229159 0.001007
CrmQueryProvider: Execute EntityName=contact 0.1241589 0.001243
CrmQueryProvider: Execute End: duration: 2 ms 0.1255817 0.001423
aspx.page End Render 0.1334645 0.007883
Jun 19, 2011 at 5:17 PM

Did you ever get the performance issue resolved. I'm experiencing roughly the same performance.

Jun 19, 2011 at 6:16 PM

Both of his traces were around 130ms, and not 10-13 seconds.  I suspect that there was something else in his environment that was blocking the browser.  For example, having IE smartscreen enabled but not having an active internet connection will add about 15 seconds to every page request.  Another thing is that the portal uses jscript and css files that are loaded from public CDN links, and again, if the Internet is not accessible, this would be an issue.  Egoddard, please page the trace of a cached page that you feel is taking 10-15 seconds long.  Another useful trace to have would be a fiddler trace that would go along with the asp.net trace of that page.

Jun 19, 2011 at 9:38 PM

We indeed didn't have an active internet connection in our (closed) test environment. When we moved the development of this project to a machine with access to the internet the problem wa resolved.

What frustrated me is that none of this is/was documented anywhere... It would have saved us an awful lot of time if it had.

Jun 20, 2011 at 8:16 AM

My issue seems very similar. I turned on the asp trace and once the initial load had completed the times were very respectable. When I run the portal website from my local machine over the internet it is fine, when run on the server it is dog slow. I check that smartscreen was disabled, must be something else. Would love to know what it is, but I don't have the time to investigate further.

Thanks for you help

Jun 20, 2011 at 2:12 PM

If you have access to the 2010 demo VPC, I would recommend downloading the portal code from there.  I had removed all external internet dependencies, including the use of scripts from CDNs, the use of the Assira Captcha, and the use of Live ID.

Another tool you will find very easy for troubleshooting is Fiddler. With that tool, you will easily recognize the requests that are taking a long time or that are reaching out to the Internet.

Apr 26, 2012 at 12:20 PM

I am also experiencing exceptionally slow loading of pages, 20-60 seconds, and then other times it will seem to load in just a couple of seconds. Got this portal hosted on Azure, I don't know if this has something to do with the problem. I can't believe that the site is caching with these times....