Archive for June, 2017

SharePoint Custom Solution Crashes IIS Worker Process (w3wp.exe) – Part 2

In Part 1 of this series, I discussed an issue we were having in one of our SharePoint 2013 farms and how I determined the issue was occurring because of a set of event receivers acting on the library.  In this post, I will discuss the code being used and what the final result was determined to be.  Stick around, it’s not what you think.

To be terribly honest nothing jumped out at me while looking over the code.  The initial review of the code indicated the issue could be around where the event receiver was trying to determine if the user adding the file was a member of the site owner group.  The original code was:

private void ProcessItemIfAuthorized(SPItemEventProperties properties, string errorMessage, bool isItemAdding)
{
    bool isFile;
    bool isSiteOwner = false;

    //Get the list of groups user is a part of.  Find if a part of site Owners
    SPSecurityManager secMgr = new SPSecurityManager();            
    List<string> spGroupsInWeb = secMgr.GetSPGroupsInWeb(properties.Web);

    //Loop through each group in the web.  If the group is the owner group, check to see if user exists within.
    foreach(string spGroup in spGroupsInWeb)
    {
        if(spGroup.Contains("<NAME OF OWNER GROUP>"))
        {
            isSiteOwner = secMgr.CheckIfUserInSPGroup(properties.Web, spGroup, secMgr.ParseUserIDFromClaim(properties.UserLoginName));
        }
    }

This seems pretty straight forward, but when “CheckIfUserInSPGroup” is called things aren’t quite as kosher.

public bool CheckIfUserInSPGroup(SPWeb spWeb, string groupUserName, string userName)
{
    bool maxReached = false;
    bool existsInGroup = false;

    if (!existsInGroup)
    {
        SPSecurity.RunWithElevatedPrivileges(delegate()
        {
            using (SPSite spSite = new SPSite(spWeb.Site.ID))
            {
                using (SPWeb currentWeb = spSite.OpenWeb(spWeb.ID))
                {
                    foreach (SPPrincipalInfo accountInfo in SPUtility.GetPrincipalsInGroup(currentWeb, groupUserName, int.MaxValue - 1, out maxReached))
                    {
                        //check to see if the account we are looking at is a nested group.  If so call the function again to dig deeper.
                        if (accountInfo.PrincipalType == SPPrincipalType.SecurityGroup)
                        {
                            existsInGroup = this.CheckIfUserInSPGroup(spWeb, accountInfo.LoginName, userName);

                            if (existsInGroup)
                            {
                                break;
                            }
                        }
                        else
                        {
                            if (this.ParseUserIDFromClaim(accountInfo.LoginName) == userName)
                            {
                                existsInGroup = true;
                                break;
                            }
                        }
                    }
                }
            }
        });

Again, normally not a huge issue, except that best practices state that you shouldn’t instantiate SPSite, SPWeb or SPList objects within an Event Receiver.  The reason for this is it causes extra database calls (more information here: https://msdn.microsoft.com/en-us/library/office/ee724407(v=office.14).aspx).  I thought this could be the culprit, but wasn’t convinced.  If this was the issue, why does it work fine for years and then suddenly stop working?  The reason the code is instantiating the SPSite and SPWeb object is it is used elsewhere in the solution and could be called by users who do not have the required access.  The same goes for the event receiver.  If I do not have access to control security groups in the site, I get an UnauthorizedAccessException.

So I thought, why not just use that.  We can safely assume that if the UnauthorizedAccessException error is thrown, the user is not in the Owners group.  So I updated the code with a try\catch (why one wasn’t already being used I don’t know) and added some logic into the catch.  Not generally the best method, but when used for targeted exceptions I believe acceptable IMHO.

//Loop through each group in the web.  If the group is the owner group, check to see if user exists within.
foreach(string spGroup in spGroupsInWeb)
{
    if(spGroup.Contains("<NAME OF OWNER GROUP>"))
    {
        try
        {
            isSiteOwner = secMgr.CheckIfUserInSPGroupEvntRcvr(properties.Web, spGroup, secMgr.ParseUserIDFromClaim(properties.UserLoginName));                        
        }
        //If authorization exception is fired, then we can assume the user is NOT in the owners group
        catch(UnauthorizedAccessException exNotAuthorized)
        {
            SPDiagnosticsService.Local.WriteTrace
                (
                    0,
                    new SPDiagnosticsCategory("App Security", TraceSeverity.High, EventSeverity.ErrorCritical),
                    TraceSeverity.High,
                    exNotAuthorized.ToString(),
                    string.Empty
                );

            isSiteOwner = false;
        }
        catch(Exception ex)
        {
            SPDiagnosticsService.Local.WriteTrace
                (
                    0,
                    new SPDiagnosticsCategory("App Security", TraceSeverity.High, EventSeverity.ErrorCritical),
                    TraceSeverity.High,
                    ex.ToString(),
                    string.Empty
                );

            //have to assume they don't have necassary access so files aren't added or deleted upon error
            isSiteOwner = false;
        }
    }
}

I also created a new method for the event receiver to call.  I couldn’t modify the existing one, as it contained valid logic to handle users without access and was being used elsewhere.

        public bool CheckIfUserInSPGroupEvntRcvr(SPWeb spWeb, string groupUserName, string userName)
        {
            bool maxReached = false;
            bool existsInGroup = false;

            if (!existsInGroup)
            {
                foreach (SPPrincipalInfo accountInfo in SPUtility.GetPrincipalsInGroup(spWeb, groupUserName, int.MaxValue - 1, out maxReached))
                {
                    //check to see if the account we are looking at is a nested group.  If so call the function again to dig deeper.
                    if (accountInfo.PrincipalType == SPPrincipalType.SecurityGroup)
                    {
                        existsInGroup = this.CheckIfUserInSPGroupEvntRcvr(spWeb, accountInfo.LoginName, userName);

                        if (existsInGroup)
                        {
                            break;
                        }
                    }
                    else
                    {
                        if (this.ParseUserIDFromClaim(accountInfo.LoginName) == userName)
                        {
                            existsInGroup = true;
                            break;
                        }
                    }
                }
            }

            return existsInGroup;
        }

So I moved the code into Pre-Prod and tried it out.  No change.  Still hanging, throwing errors and crashing the app pool.

Next step was to install Visual Studio into Pre-Prod and attach to the IIS Worker process.  I followed the code until it got into the newly created CheckIfUserInSPGroupEvntRcvr method.  There it stayed.  It kept looping through the AD users and groups within the SharePoint group.  As it was looping I watched the worker process memory usage grow and grow until it finally crashed again.  This didn’t make any sense as there are NOT that many users in these groups.

The Cause of it All

I took a look at the ownership group for the site I was testing with.  Like most (not all) of our project sites, it contained an AD group that contains our project team.  Let’s call that group All-Project.  All-Project had about a dozen users within it, however, there was an anomaly.  It also contained the Owners group from another project site.  This was an oddity.  I took a look at the Owner group and it also contained the same All-Project group. There was the culprit.

As you can see in the code above, it is designed for nested groups, so if the code hits a group it digs down to see if the nested group contains the user.  Because this Owner group was added (in error I found out while trying to figure out why it was there) to the All-Projects group, the code would dig into All-Projects then to the Owners group, from there back into the All-Projects group and then back into the Owners group… see where I am going with this?  By adding that single group to the All-Projects group in error an infinite recursion loop was created in the code.

The Final Fix

So the final fix was not an environmental change or a code modification.  It was simply to remove the Owners group from the All-Projects group.  Once that was done, the original code functioned as designed.  If this becomes a regular occurrence I will have to update the code to handle such an event, but in this case, I didn’t.  The farm is in containment (no further development short of break\fix) and the issue has not occurred for two years before this.  I hope the steps I documented in this blog series helps others out.

 

Thanks for reading!

SharePoint Custom Solution Crashes IIS Worker Process (w3wp.exe) – Part 1

Had a doozy of an issue the other day.  All of a sudden, a SharePoint farm that has been chugging along with no changes suddenly started having some weird issues.  Users could open, view, edit documents, but as soon as they attempted a save or an upload of a new document things started to go bad.  If they were using Windows Explorer they received the error: “The specified network name is no longer available”

SharePoint Custom Solution Crashes IIS Worker Proces - Windows Explorer Error

If they were using the GUI the upload form hung for a while and eventually reverted to “The Page Cannot be Displayed”

At the same time, we were getting reports of users in other areas of the farm getting a very slow response within SharePoint.  What was really confusing about this was that the issue was happening to just a single site collection in the farm.

Errors Received

Windows Event Log

We were receiving a number of errors besides those at the end user level.  The server event log indicated our app pool was crashing.  The error received was actually a warning (to me if an app pool is crashing, it should be an error) with the msg:

A process serving application pool ‘SharePoint Web Apps’ suffered a fatal communication error with the Windows Process Activation Service. The process id was ‘6292’. The data field contains the error number.

SharePoint Custom Solution Crashes IIS Worker Proces - EventLogError

In the multiple WFE environment it was happening back and forth between the two serves indicating the load balance was doing its job.  It also indicated why people were seeing slow response.  Each time the app pool failed, it had to restart and then reload the SharePoint environment (like you see after an IIS Reset).

ULS Logs

The ULS logs were something else.  In this particular environment our logs usually range from 5MB-40MB in size for a 30 min period.  When I ran a one minute log export using “Merge-SPLogFIle” the exported file was 1.3 GB.  Nothing screamed error at me, however there were a couple of things standing out.

06/21/2017 10:30:38.00        w3wp.exe (0x112C)        0x1E58        SharePoint Foundation        Performance        naqx        Monitorable        Potentially excessive number of SPRequest objects (16) currently unreleased on thread 46.  Ensure that this object or its parent (such as an SPWeb or SPSite) is being properly disposed. This object is holding on to a separate native heap. Allocation Id for this object: {C3DC973B-90B4-4974-A33D-A5A05A722DF7} Stack trace of current allocation:    at Microsoft.SharePoint.SPGlobal.CreateSPRequestAndSetIdentity(SPSite site, String name, Boolean bNotGlobalAdminCode, String strUrl, Boolean bNotAddToContext, Byte[] UserToken, SPAppPrincipalToken appPrincipalToken, String userName, Boolean bIgnoreTokenTimeout, Boolean bAsAnonymous)     at Microsoft.SharePoint.SPWeb.InitializeSPRequest()     at Microsoft.SharePoint.SPWeb.EnsureSPRequest()     at Microsoft.SharePoint.SPSite.OpenWeb(String strUrl, Int32 mondoHint)     at Microsoft.SharePoint.SPSite.OpenWeb(Guid gWebId, Int32 mondoHint)     at Microsoft.SharePoint.SPSite.OpenWeb(Guid gWebId)….

06/21/2017 10:31:21.09        w3wp.exe (0x112C)        0x1E58        SharePoint Foundation        General        8m90        Medium        1045 heaps created, above warning threshold of 128. Check for excessive SPWeb or SPSite usage.        a8dafd9d-9faa-70d5-b0e7-8c1711386713

So this screamed of some custom code (which we do have) running that is not disposing of the SPSite or SPWeb objects properly.  Why it suddenly became a problem I don’t know.  We did have security patches happen on the server over the weekend.  I didn’t think it likely to be the cause as the environment had been used for a day and a half with no issues.  We backed out of the patch anyways, but didn’t affect the issue occurring.  What was also confusing was this issue was also occurring in our Pre-Prod environment.  The silver lining is now I could really do some troubleshooting without affecting sites that were functioning or production data.

I finally tracked down the issue to an event receiver we have running in our environment.  The project sites all of the same structure and it was decided that code would be used to enforce this structure.  To that end, event receivers were built to ensure folders at certain levels (library root, root +1 level and root +2 levels) were not deleted nor files or folders at those levels were added.  I took a guess that these event receivers were causing the issues.  Using PowerShell I removed the event receivers from a library being affected.  In case you need this for something else the code to remove a list event receiver is:

$siteColURL = "<Site URL>";

$spSite = Get-SPSite $siteColURL

foreach($spWeb in $spSite.AllWebs)
{
    $spList = $spWeb.Lists["<LIBRARY NAME"];
    
    try 
    {
        for($i = $splist.EventReceivers.Count - 1; $i -ge 0; $i--)
        {
            $eventReceiver = $spList.EventReceivers[$i];
            if($eventReceiver.Class -eq "<EVENT RECEIVER CLASS>")
            {
                $eventReceiver.Delete();
            }
        }

        $spList.Update();
        
        Write-Host("Updated library for site: {0}" -f $spWeb.URL);
    }
    catch 
    {
        $ErrorMessage = $_.Exception.Message;
        Write-Host ("{0}: An error occurred deleting the event receiver for site: {1}.  Error received: {2}" -f `
                        (get-date).ToString("yyyy-MM-dd HH:mm:ss"), $spWeb.URL, $ErrorMessage) -ForegroundColor Red
    }    
}

In the above code (which removes the event receivers from ALL specified libraies in ALL subsites) I used the event receiver class to find the items I wanted to remove.  You can also use .Name and .Assembly if you wish. I used Class simply because when the sites were created and the receivers attached, no names were given.  With the event receivers removed, users were now able to upload and save documents.  So I had indeed found the culprit.  Now to determine why.

I’ll cover the review of the code and the final determination of the cause of the issue in Part 2 of this series.

 

Thanks for reading!