This project has moved. For the latest updates, please go here.

Error in FillResolve when user has permission to site via 'Everyone'

Jan 27, 2015 at 2:22 PM
Use case: a valid user attempts login. The user has permissions to the site via 'Everyone'. This error does not occur when the user has permissions assigned directly or has no permissions at all.

The user attempts to log in. The user is found in the directory, and claims are augmented with groups. But then another call is made into FillResolve. The user sees a blank page, and after 2 minutes there is a timeout and an error. The ULS shows this:

01/27/2015 15:08:29.03 w3wp.exe (0x22E4) 0x4418 AzureCP Claims Augmentation 1337 VerboseEx [AzureCP] FillClaimsForEntity called, incoming envity: "0e.t|azure ad|sharepointmember@xxxxxxxxx.com", claim type: "http://schemas.microsoft.com/sharepoint/2009/08/claims/userid", claim issuer: "SecurityTokenService" c9e1e39c-61dd-d0d8-c8a4-e4af4c6621e1
01/27/2015 15:08:29.03 w3wp.exe (0x22E4) 0x4418 AzureCP Core 1337 Verbose [AzureCP] AzureCPConfig PersistedObject found, version: 674153, previous version: 674153 c9e1e39c-61dd-d0d8-c8a4-e4af4c6621e1
01/27/2015 15:08:29.15 w3wp.exe (0x22E4) 0x4418 AzureCP Lookup 1337 Medium [AzureCP] Search on xxxxxxxxx.onMicrosoft.com took 126ms and found 1 result(s) for 'sharepointmember@xxxxxxxxx.com' c9e1e39c-61dd-d0d8-c8a4-e4af4c6621e1 01/27/2015 15:08:29.15 w3wp.exe (0x22E4) 0x4418 AzureCP Lookup 1337 Verbose [AzureCP] 1 permission(s) to create after filtering c9e1e39c-61dd-d0d8-c8a4-e4af4c6621e1
01/27/2015 15:08:29.15 w3wp.exe (0x22E4) 0x4418 AzureCP Claims Picking 1337 Verbose [AzureCP] Added metadata "DisplayName" with value "Sharepoint Member" to permission c9e1e39c-61dd-d0d8-c8a4-e4af4c6621e1
01/27/2015 15:08:29.15 w3wp.exe (0x22E4) 0x4418 AzureCP Claims Picking 1337 Verbose [AzureCP] Added metadata "Email" with value "Sharepoint.Member@xxxxxxxxx.com" to permission c9e1e39c-61dd-d0d8-c8a4-e4af4c6621e1
01/27/2015 15:08:29.15 w3wp.exe (0x22E4) 0x4418 AzureCP Claims Picking 1337 Verbose [AzureCP] Created permission: display text: "SharepointMember@xxxxxxxxx.com", value: "SharepointMember@xxxxxxxxx.com", claim type: "http://schemas.xmlsoap.org/ws/2005/05/identity/claims/upn", and filled with 2 metadata. c9e1e39c-61dd-d0d8-c8a4-e4af4c6621e1
01/27/2015 15:08:29.15 w3wp.exe (0x22E4) 0x4418 AzureCP Claims Augmentation 1337 Verbose [AzureCP] Getting membership of user "sharepointmember@xxxxxxxxx.com" on tenant xxxxxxxxx.onMicrosoft.com c9e1e39c-61dd-d0d8-c8a4-e4af4c6621e1
01/27/2015 15:08:29.21 w3wp.exe (0x22E4) 0x4418 AzureCP Claims Augmentation 1337 Medium [AzureCP] user sharepointmember@xxxxxxxxx.com augmented with Azure AD group "SPTestGroup001" (claim type http://schemas.microsoft.com/ws/2008/06/identity/claims/role). c9e1e39c-61dd-d0d8-c8a4-e4af4c6621e1
01/27/2015 15:08:29.24 w3wp.exe (0x1AE8) 0x00A4 AzureCP Core 1337 VerboseEx [AzureCP] FillResolve(SPClaim) called, incoming claim value: "sharepointmember@xxxxxxxxx.com", claim type: "http://schemas.xmlsoap.org/ws/2005/05/identity/claims/upn", claim issuer: "TrustedProvider:azure ad" c9e1e39c-61dd-d0d8-c8a4-e4af4c6621e1
01/27/2015 15:08:29.24 w3wp.exe (0x1AE8) 0x00A4 AzureCP Core 1337 Verbose [AzureCP] AzureCPConfig PersistedObject found, version: 674153, previous version: 674153 c9e1e39c-61dd-d0d8-c8a4-e4af4c6621e1
01/27/2015 15:10:31.56 w3wp.exe (0x1AE8) 0x00A4 AzureCP Lookup 1337 Unexpected [AzureCP] Unexpected error while querying tenant xxxxxxxxx.onMicrosoft.com: System.Threading.ThreadAbortException: Thread was being aborted., Callstack: at System.Threading.Monitor.ObjWait(Boolean exitContext, Int32 millisecondsTimeout, Object obj) at System.Threading.ManualResetEventSlim.Wait(Int32 millisecondsTimeout, CancellationToken cancellationToken) at System.Threading.Tasks.Task.SpinThenBlockingWait(Int32 millisecondsTimeout, CancellationToken cancellationToken) at System.Threading.Tasks.Task.InternalWait(Int32 millisecondsTimeout, CancellationToken cancellationToken) at System.Threading.Tasks.Task1.GetResultCore(Boolean waitCompletionNotification) at azurecp.AzureCP.QueryAzureAD(Expression1 userQuery, Expression1 groupQuery, AzureTenant coco) at azurecp.AzureCP.<>c__DisplayClass21.<QueryAzureADCollection>b__20(AzureTenant coco) c9e1e39c-61dd-d0d8-c8a4-e4af4c6621e1
01/27/2015 15:10:31.56 w3wp.exe (0x1AE8) 0x00A4 AzureCP Claims Picking 1337 Unexpected [AzureCP] Unexpected error in FillResolve(SPClaim): System.Threading.ThreadAbortException: Thread was being aborted., Callstack: at System.Threading.Tasks.Task.<>c__DisplayClass11.<ExecuteSelfReplicating>b__10(Object param0) at System.Threading.Tasks.Task.Execute() at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx) at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx) at System.Threading.Tasks.Task.ExecuteWithThreadLocal(Task& currentTaskSlot) at System.Threading.Tasks.Task.ExecuteEntry(Boolean bPreventDoubleExecution) at System.Threading.Tasks.ThreadPoolTaskScheduler.TryExecuteTaskInline(Task task, Boolean taskWasPreviouslyQueued) at System.Threading.Tasks.TaskScheduler.TryRunInline(Task task, Boolean taskWasPreviouslyQueued) at System.Threading.Tasks.Task.InternalRunSynchronously(TaskScheduler scheduler, Boolean waitForCompletion) at System.Threading.Tasks.Parallel.ForWorker[TLocal](Int32 fromInclusive, Int32 toExclusive, ParallelOptions parallelOptions, Action
1 body, Action2 bodyWithState, Func4 bodyWithLocal, Func1 localInit, Action1 localFinally) at System.Threading.Tasks.Parallel.ForEachWorker[TSource,TLocal](IEnumerable1 source, ParallelOptions parallelOptions, Action1 body, Action2 bodyWithState, Action3 bodyWithStateAndIndex, Func4 bodyWithStateAndLocal, Func5 bodyWithEverything, Func1 localInit, Action1 localFinally) at System.Threading.Tasks.Parallel.ForEach[TSource](IEnumerable1 source, Action1 body) at azurecp.AzureCP.QueryAzureADCollection(Expression1 userQuery, Expression1 groupQuery, String input) at azurecp.AzureCP.BuildFilterAndProcessResults(String input, List1 azureObjectsToQuery, Boolean exactSearch, Uri context, String[] entityTypes, List1& results) at azurecp.AzureCP.<>c__DisplayClass38.<FillResolve>b__36() c9e1e39c-61dd-d0d8-c8a4-e4af4c6621e1

01/27/2015 15:10:31.56 w3wp.exe (0x1AE8) 0x00A4 SharePoint Foundation Claims Authentication 8307 Critical An exception occurred in AzureCP claim provider when calling SPClaimProvider.FillResolveClaim(): Thread was being aborted.. c9e1e39c-61dd-d0d8-c8a4-e4af4c6621e1
01/27/2015 15:10:31.56 w3wp.exe (0x1AE8) 0x00A4 SharePoint Foundation Claims Authentication amcbr High [Forced due to logging gap, cached @ 01/27/2015 15:08:29.24, Original Level: Verbose] Claim provider does not support user keys. Claim Provider: '{0}' c9e1e39c-61dd-d0d8-c8a4-e4af4c6621e1
Coordinator
Jan 28, 2015 at 11:16 AM
Hello, I think I reproduce the same issue (I don't get the ThreadAbortException but it hangs and nothing happens), I'll investigate it further and update this post with my findings.
cheers,
Yvan
Coordinator
Jan 29, 2015 at 2:44 PM
Hello,

this is a tough deadlock situation on 2 threads that want to lock object ASP.global_asax:
1) AzureCP Thread calls async method DataServiceContextWrapper.ExecuteBatchAsync (from AAD Graph API) to query Azure tenant, and waits for completion.
2) ExecuteBatchAsync queries Azure tenant in a separate thread and gets the response. But for some reason it tries to acquire a lock on object ASP.global_asax, that is already owned by AzureCP thread, so it waits and never completes, which causes the deadlock.

Now the big question is why this deadlock occurs only in this scenario: this is probably because claims provider is called by a SharePoint HTTPModule, and only in this code path object ASP.global_asax is locked.

At this point I don't know how I'm going to resolve this: clearly it's not a bug in my code, and I don't know if/how to workaround this (AAD Graph API uses async methods everywhere).
I'll continue to dig this and I'll post an update when I have something new

cheers,
Yvan
Jan 29, 2015 at 2:59 PM

Yvand,

Thanks for the update. For now, we will avoid the use of ‘Everyone’ when setting permissions.

Greg Nalesnik

intellinet | principal consultant | 404.442.8624 direct | 404.717.4095 mobile

MICROSOFT SOUTHEAST PARTNER OF THE YEAR 2012 & 2013

May 1, 2015 at 9:55 AM
Hi Yvand. Wondering if you have any further thoughts on this issue. This also occurs for me if I apply permission to a custom Azure group as well.. i.e. create a group in Azure, then assign read permission to a site collection, all users the cannot login in. And as above, this happens if I apply the "EveryOne" permission or also the "All Users" permission for the custom claims provider.

As soon as you remove the permission you can login again.

Thanks for a great tool by the way ! Youve put alot of work into it.

Cheers
John
May 1, 2015 at 1:39 PM

I had the same problem and coded a workaround.

To diagnose, I set the debug level to VerboseEx. I could see that when a call was made to FillResolve for the OriginalIssuer of ‘SecurityTokenService’, everything worked OK. But then I saw another call into the routine with an OriginalIssuer of my TrustedProvider, and that is the one that failed.

I added a check to exit the routine if the OriginalIssuer is not the SecurityTokenService.

I do not know if this will cause any other problems, but my Azure AD users granted permissions via an Azure AD group can now log in.

From the ULS logs, this call is successful:

[AzureCP] FillClaimsForEntity called, incoming envity: "0e.t|azure ad|[email removed]", claim type: "http://schemas.microsoft.com/sharepoint/2009/08/claims/userid", claim issuer: "SecurityTokenService"

But this call fails:

[AzureCP] FillResolve(SPClaim) called, incoming claim value: "[email removed]", claim type: "http://schemas.xmlsoap.org/ws/2005/05/identity/claims/upn", claim issuer: "TrustedProvider:azure ad"

Greg Nalesnik

intellinet | principal consultant | 404.442.8624 (w) | 404.717.4095 (c)

management consulting & microsoft-centric technology services

2014-2013-2012-2011 Microsoft Partner of the Year (SE/NE Districts)

Coordinator
May 4, 2015 at 1:22 PM
Hello, yes I did not forget this deadlock.
I tried many variants in the code to avoid it, but it occurs in Context.ExecuteBatchAsync method of Graph API, only in this specific scenario, but I don't understand why it occurs in this scenario and not in others.
Actually I was more or less resigned to try to retrieve results in a different way (and hoping it would not cause again a deadlock).
Greg, I will test your workaround, but I don't know what could be the side effects of not resolving the entity when the OriginalIssuer is the TrustedProvider, so we should be careful with it.
I'll update this thread with the results of my tests, hopefully this week or next week.
Yvan
May 5, 2015 at 12:15 PM
Hi Yvan and Greg, thanks both for your input and Yvan, your continual work on a great tool ! I too will test the mentioned ideas. Cheers John
Coordinator
May 6, 2015 at 9:04 AM
Hi Greg,

I think it's really not possible to use your workaround, if it is implemented then no permission can be added to the site anymore.
Actually, in FillResolve (SPClaim) method, AzureCP should
  • always resolve entity if trusted issuer is AzureCP
  • never resolve entity if trusted issuer is not AzureCP
Can you confirm you cannot grant any new permission?
May 6, 2015 at 1:30 PM
Hi Yvand, I'm at Ignite this week but will try this tonight. Thanks for the follow up!

Sent from my mobile

May 11, 2015 at 2:43 PM
I have similar behavior except I added an Azure Group, I added the group to the SP site, however a member of this group is getting a Run time error:

[AzureCP] Search on conposo.onmicrosoft.com took 148ms and found 1 result(s) for 'gaspa@conposo.onmicrosoft.com' [AzureCP] Added metadata "DisplayName" with value "Luis" to permission
[AzureCP] Created permission: display text: "gaspa@conposo.onmicrosoft.com", value: "gaspa@conposo.onmicrosoft.com", claim type: "http://schemas.xmlsoap.org/ws/2005/05/identity/claims/upn", and filled with 1 metadata.
[AzureCP] Getting membership of user "gaspa@conposo.onmicrosoft.com" on tenant conposo.onmicrosoft.com
[AzureCP] user gaspa@conposo.onmicrosoft.com augmented with Azure AD group "sharepoint.admins" (claim type http://schemas.microsoft.com/ws/2008/06/identity/claims/role).


[AzureCP] Unexpected error while querying tenant conposo.onmicrosoft.com: System.Threading.ThreadAbortException: Thread was being aborted., Callstack:
at System.Threading.Monitor.ObjWait(Boolean exitContext, Int32 millisecondsTimeout, Object obj)
at System.Threading.ManualResetEventSlim.Wait(Int32 millisecondsTimeout, CancellationToken cancellationToken)
at System.Threading.Tasks.Task.SpinThenBlockingWait(Int32 millisecondsTimeout, CancellationToken cancellationToken)
at System.Threading.Tasks.Task.InternalWait(Int32 millisecondsTimeout, CancellationToken cancellationToken)
at System.Threading.Tasks.Task1.GetResultCore(Boolean waitCompletionNotification)
at azurecp.AzureCP.QueryAzureAD(Expression
1 userQuery, Expression1 groupQuery, AzureTenant coco)
at azurecp.AzureCP.QueryAzureADCollection(Expression
1 userQuery, Expression1 groupQuery, String input)


[AzureCP] Unexpected error in FillResolve(SPClaim): System.Threading.ThreadAbortException: Thread was being aborted., Callstack:
at azurecp.AzureCP.QueryAzureADCollection(Expression
1 userQuery, Expression1 groupQuery, String input)
at azurecp.AzureCP.BuildFilterAndProcessResults(String input, List
1 azureObjectsToQuery, Boolean exactSearch, Uri context, String[] entityTypes, List`1& results)
at azurecp.AzureCP.<>c__DisplayClass33.<FillResolve>b__31()
Coordinator
May 13, 2015 at 2:05 PM
Hello, your error corresponds to this deadlock issue.
I made some tests and I think I have a working solution, I need some time to integrate it properly and run some tests, I'll reply back when I'll have further update
thanks
Yvan
Jul 6, 2015 at 8:51 AM
Hi Yvand, just wondering if you had any luck with this ? or had a release i could do some testing on for you. Many thanks
John
Coordinator
Sep 10, 2015 at 5:12 PM
Hello,
I apologize for the very late reply, but I was very busy.
I anyway have good news: I finally fixed the deadlock issue in v2.6.
Please note that I moved the project to GitHub, and this is where the new release can be found.
Thanks,
Yvan
Sep 10, 2015 at 6:50 PM
Hi Yvan, completely understand.
Thats great news ! Thanks for the amazing work on your code base. Ill install in my next available window and see how it goes.
Cheers
John