Slow SharePoint Blog

Question

The SharePoint 2010 blog can at times be very slow when rendering individual posts.

The time is generally due to the following operations:

DataBinding DataFormWebPart (Posts‭[1]‬) (2654.17 ms)  
EnsureListItemsData (133.25 ms)   
DataBinding DataFormWebPart (Posts‭[2]‬) (2679.60 ms)  
EnsureListItemsData (14.23 ms) 
DataBinding DataFormWebPart (Comments) (3591.15 ms)  
EnsureListItemsData (82.40 ms) 
DataBinding DataFormWebPart(Categories) (2604.30 ms)  
EnsureListItemsData (14.02 ms)

The lists are really small, any ideas?

Here are the Database Queries for the above trace:

proc_FetchDocForHttpGet 30.54 ms
SELECT t10.*, t11.[ntext1], 14.59 ms
proc_GetTpWebMetaDataAndListMetaData    12.74 ms
proc_EnumLists' CommandType:    22.61 ms
proc_GetTpWebMetaDataAndListMetaData    13.40 ms
proc_GetWebMetainfo 10.63 ms
proc_GetListWebParts    11.43 ms
EXEC @wssp0=proc_GetFolderContentTypeOrder  9.24 ms
proc_GetTpWebMetaDataAndListMetaData    13.20 ms
proc_GetTpWebMetaDataAndListMetaData    15.03 ms
proc_GetListMetaDataAndEventReceivers   12.35 ms
proc_GetListMetaDataAndEventReceivers   13.85 ms
SELECT t10.*, t11.[ntext1], 14.17 ms
proc_GetTpWebMetaDataAndListMetaData    13.60 ms
proc_GetListMetaDataAndEventReceivers   11.35 ms
proc_GetListMetaDataAndEventReceivers   12.15 ms
proc_GetListMetaDataAndEventReceivers   13.73 ms
proc_GetListMetaDataAndEventReceivers   11.25 ms
SELECT t10.*, t11.[ntext1], 12.58 ms
DECLARE @DocParentIdForRF   129.13 ms
proc_GetListWebParts    36.04 ms
DECLARE @DN nvarchar(256),@LN   37.49 ms
proc_UpdateWebPartCache 9.52 ms
DECLARE @DocParentIdForRF   11.68 ms
DECLARE @DN nvarchar(256),@LN   26.94 ms
proc_UpdateWebPartCache 12.09 ms
DECLARE @DocParentIdForRF   78.80 ms
DECLARE @DN nvarchar(256),@LN   48.41 ms
proc_UpdateWebPartCache 12.79 ms
DECLARE @DocParentIdForRF   11.13 ms
proc_GetListWebParts    13.34 ms
DECLARE @DN nvarchar(256),@LN   16.94 ms
proc_UpdateWebPartCache 12.07 ms
proc_GetTpWebMetaDataAndListMetaData    13.33 ms
proc_GetTpWebMetaDataAndListMetaData    10.26 ms
proc_GetTpWebMetaDataAndListMetaData    9.67 ms
proc_SecListSiteGroupsContainingUser    8.30 ms
proc_SecListScopeGroups 16.54 ms
proc_SecGetUserPermissionOnGroup    8.49 ms
proc_SecGetUserPermissionOnGroup    7.94 ms
proc_SecGetUserPermissionOnGroup    8.01 ms
proc_SecGetUserPermissionOnGroup    5.55 ms
proc_SecGetUserPermissionOnGroup    4.28 ms
proc_SecGetUserPermissionOnGroup    4.16 ms
proc_SecGetUserPermissionOnGroup    6.14 ms
proc_SecGetUserPermissionOnGroup    8.33 ms
proc_SecGetUserPermissionOnGroup    8.10 ms
dbo.Orgle_GetUserOrgleList  5.71 ms
dbo.Orgle_GetUserOrgleList  5.31 ms
dbo.profile_GetUserGUID 6.03 ms

Here are the service calls:

ExecuteWcfOperation:http://Microsoft.Office.Server.UserProfiles/GetUserData 20.02 ms

Here are events offset:

SPWebPartManager OnLoad +0.00 ms
Posts OnLoad    +0.16 ms
Posts OnLoad    +0.24 ms
Comments OnLoad +0.30 ms
Categories OnLoad   +0.36 ms
New Comment OnLoad  +12.87 ms
Archives OnLoad +34.84 ms
Blog Tools OnLoad   +34.86 ms
SPWebPartManager OnPreRender    +0.00 ms
Posts OnPreRender   +2655.80 ms
Posts OnPreRender   +5336.52 ms
Comments OnPreRender    +8930.95 ms
Categories OnPreRender  +11537.97 ms
New Comment OnPreRender +11538.02 ms
Archives OnPreRender    +11538.70 ms
Blog Tools OnPreRender  +11538.78 ms

Answer 1

Ouch.

Your SQL Server seems very slow

I think something is slowing down your SQL Server. To be sure, can you check that all SharePoint sites are slow during that time ? (not only the blog)

I would recommand you to take a deep look onto the SQL Server, in particular :

• Is there an antivirus that may be the cause ?
• Is there a robot used to copy data that may be the cause ?
• ...

On the SharePoint side, take a look a the logs to check if someone/something is making a ton of requests to your site.

Answer 2

The problem was resolved by deactivating the SharePoint Publishing web feature on the Blog. Looks like there are some incompatibilities beetween the blog and the publishing web feature. The Execution time for binding DataFormWebPart went from ~3s to ~1ms.

Answer 3

Did some reflection on this SharePoint Publishing web feature and it seems it has a connection to the Publishing Feature so can it be something here that slows it down (Workflows?):

internal void Unprovision()
{

    string siteUrl = this.currentWeb.Site.Url;
    SPSecurity.RunWithElevatedPrivileges(delegate {
        using (VariationSettings settings = VariationSettingsFactory.CreateVariationSettings(siteUrl, true))
        {
            PublishingWeb pubWeb = PublishingWeb.GetPublishingWeb(this.currentWeb);
            SPList relationshipList = settings.GlobalRelationshipList;
            VariationsCleanup.RemoveVariationArtifactsForWeb(pubWeb, false, relationshipList, true, true);
        }
   });
    ProvisioningHelper.DeleteListIfEmpty(this.currentWeb, "WorkflowTasks");
    ProvisioningHelper.DeleteListIfEmpty(this.currentWeb, "WorkflowHistory");
    if (!ProvisioningHelper.DeleteDocLibIfEmpty(this.currentWeb, PublishingWeb.GetPagesListName(this.currentWeb)))
    {
        ProvisioningHelper.DisableApprovalWorkflowOnSubmit(this.currentWeb, PublishingWeb.GetPagesListName(this.currentWeb), "__PublishingPagesApprovalWorkflowId");
    }
    if (!ProvisioningHelper.DeleteDocLibIfEmpty(this.currentWeb, "PublishingImages"))
    {
        ProvisioningHelper.DisableApprovalWorkflowOnSubmit(this.currentWeb, "PublishingImages", "__PublishingImagesApprovalWorkflowId");
    }
    if (!ProvisioningHelper.DeleteDocLibIfEmpty(this.currentWeb, "Documents"))
    {
        ProvisioningHelper.DisableApprovalWorkflowOnSubmit(this.currentWeb, "Documents", "__PublishingDocumentsApprovalWorkflowId");
    }
    PublishingWeb.RemovePublishingWebProperties(this.currentWeb);
}