HTTP Web Service Request (Designer Workflow) InputIdentity doesn't conatin a PrimarySid claim

Copper Contributor

I have diligently followed instructions on many sites, trying to see why copying a list item to a list in another site collection (Same farm, same application, same server even, However in different content databases), such as that posted here https://blog.portiva.nl/2016/11/03/sharepoint-designer-call-http-web-service-to-create-item-in-other... and https://sharepointdevloper.wordpress.com/2016/12/08/sharepoint-designer-call-http-web-service-to-cre...

I cannot get it to work.  The workflow sticks (and it's really basic).  It returns the following

Retrying last request. Next attempt scheduled in less than one minute. Details of last request: HTTP InternalServerError to https://spsite.contoso.com/sites/wkfltest/_api/web/lists(guid'6c5dd2bd-db15-45ee-aad1-4101763e7a19')... Correlation Id: 12df4c15-6418-1362-98a7-d7a9c682eb70 Instance Id: 1bf2bc7e-aa64-41c4-9e4c-6a6e416e2934
Invalid text value.

A text field contains invalid data. Please check the value and try again.

When I look up the Correlation ID I find the following:

Unexpected SPSecurityTokenServiceManager!EnsureSharePointLogonRequestClaims: InputIdentity doesn't conatin a PrimarySid claim. 12df4c15-6418-1362-98a7-d7a9c682eb70

I have indeed provided permissions as shown in both tutorials.

Does anyone have a suggestion as to what is wrong?  We are indeed using claims, it is a SharePoint 2016 On Premise farm.

02/13/2018 13:05:46.42               w3wp.exe (0x1B34)                                      0x0844  SharePoint Foundation                         Application Authentication          ajwpw  Medium              SPApplicationAuthenticationModule: Attached actor identity to current thread. Actor Identity:0i.t|ms.sp.ext|25cc8944-277c-4243-aa69-6b290946043f@0f4852ba-ed9a-422e-955c-c8e871973179.             12df4c15-6418-1362-98a7-d7a9c682eb70

full ULS listed below:

02/13/2018 13:05:46.42  w3wp.exe (0x1B34)                        0x0844 SharePoint Foundation          Asp Runtime                    avwhy Medium   SPRequestModule.BeginRequestHandler Begin  
02/13/2018 13:05:46.42  w3wp.exe (0x1B34)                        0x0844 SharePoint Foundation          Monitoring                     nasq Medium   Entering Monitored Scope (Request (POST:https://Sharepoint.contoso.com/sites/wkfltest/_api/web/lists(guid'6c5dd2bd-db15-45ee-aad1-4101763e7a...)). Parent=None  
02/13/2018 13:05:46.42  w3wp.exe (0x1B34)                        0x0844 SharePoint Foundation          Site Cache                     az4z8 Medium   Looking up SPSite by ID 9b56f01a-0ba1-4986-89f2-236c23806d29 in memory.  
02/13/2018 13:05:46.42  w3wp.exe (0x1B34)                        0x0844 SharePoint Foundation          Logging Correlation Data       xmnv Medium   Name=Request (POST:https://Sharepoint.contoso.com/sites/wkfltest/_api/web/lists(guid'6c5dd2bd-db15-45ee-aad1-4101763e7a...
02/13/2018 13:05:46.42  w3wp.exe (0x1B34)                        0x0844 SharePoint Foundation          Asp Runtime                    avwhz Medium   SPRequestModule.BeginRequestHandler End 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.42  w3wp.exe (0x1B34)                        0x0844 Web Content Management         Publishing                     aytib Medium   ObjectCachePerRequest Global:True, Enabled:False 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.42  w3wp.exe (0x1B34)                        0x0844 SharePoint Foundation          Claims Authentication          bjkuz Medium   Using input cookie name. CookieName: 'FedAuth'. 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.42  w3wp.exe (0x1B34)                        0x0844 SharePoint Foundation          Application Authentication     bjvyg Medium   SPApplicationAuthenticationModule: Clear outgoing token context from SpThreadContext  12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.42  w3wp.exe (0x1B34)                        0x0844 SharePoint Foundation          Monitoring                     nasq Medium   Entering Monitored Scope (Application Authentication Pipeline). Parent=SPClaimsCounterScope 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.42  w3wp.exe (0x1B34)                        0x0844 SharePoint Foundation          Claims Authentication          ah25l Medium   Json token issuer is not self issuer. IssuerName: '00000005-0000-0000-c000-000000000000'. 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.42  w3wp.exe (0x1B34)                        0x0844 SharePoint Foundation          Claims Authentication          bjvyh Medium   Set Evo outgoing token context on thread 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.42  w3wp.exe (0x1B34)                        0x0844 SharePoint Foundation          Claims Authentication          bab7j Medium   Found SPIncomingTokenContext in the thread context. 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.42  w3wp.exe (0x1B34)                        0x0844 SharePoint Foundation          Claims Authentication          bab7m High     Did not find token claim in token. ClaimType: 'scope'. 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.42  w3wp.exe (0x1B34)                        0x0844 SharePoint Foundation          Claims Authentication          bab7j Medium   Found SPIncomingTokenContext in the thread context. 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.42  w3wp.exe (0x1B34)                        0x0844 SharePoint Foundation          Claims Authentication          bab7m High     Did not find token claim in token. ClaimType: 'scp'. 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.42  w3wp.exe (0x1B34)                        0x0844 SharePoint Foundation          Claims Authentication          bab7j Medium   Found SPIncomingTokenContext in the thread context. 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.42  w3wp.exe (0x1B34)                        0x0844 SharePoint Foundation          Claims Authentication          bab7m High     Did not find token claim in token. ClaimType: 'clientappid'. 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.42  w3wp.exe (0x1B34)                        0x0844 SharePoint Foundation          Application Authentication     bjvyj Medium   ClientAppId claim does not exist. Trying forAppId claim. 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.42  w3wp.exe (0x1B34)                        0x0844 SharePoint Foundation          Claims Authentication          bab7j Medium   Found SPIncomingTokenContext in the thread context. 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.42  w3wp.exe (0x1B34)                        0x0844 SharePoint Foundation          Claims Authentication          bab7m High     Did not find token claim in token. ClaimType: 'appid'. 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.42  w3wp.exe (0x1B34)                        0x0844 SharePoint Foundation          Claims Authentication          bab7j Medium   Found SPIncomingTokenContext in the thread context. 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.42  w3wp.exe (0x1B34)                        0x0844 SharePoint Foundation          Claims Authentication          bab7m High     Did not find token claim in token. ClaimType: 'roles'. 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.42  w3wp.exe (0x1B34)                        0x0844 SharePoint Foundation          Application Authentication     a4cq8 Medium   SPApplicationAuthenticationModule: Incoming token contains actor. Trying to attach it to current thread. Incoming Actor Identity: '' 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.42  w3wp.exe (0x1B34)                        0x0844 SharePoint Foundation          Application Authentication     ajwpw Medium   SPApplicationAuthenticationModule: Attached actor identity to current thread. Actor Identity:0i.t|ms.sp.ext|25cc8944-277c-4243-aa69-6b290946043f@0f4852ba-ed9a-422e-955c-c8e871973179. 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.42  w3wp.exe (0x1B34)                        0x0844 SharePoint Foundation          Monitoring                     nasq Medium   Entering Monitored Scope (Getting Site Subscription Id). Parent=[S2S] Getting token from STS and setting Thread Identity 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.42  w3wp.exe (0x1B34)                        0x0844 SharePoint Foundation          Authentication Authorization   a7r51 Medium   SPSite as SystemAccount:  12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.42  w3wp.exe (0x1B34)                        0x0844 SharePoint Foundation          Claims Authentication          a1n25 High     Token is for a windows account. 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.42  w3wp.exe (0x1B34)                        0x0844 SharePoint Foundation          Monitoring                     b4ly Medium   Leaving Monitored Scope: (Getting Site Subscription Id) Execution Time=0.0797845537104017; CPU Milliseconds=0; SQL Query Count=0; Parent=[S2S] Getting token from STS and setting Thread Identity 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.42  w3wp.exe (0x1B34)                        0x0844 SharePoint Foundation          Monitoring                     nasq Medium   Entering Monitored Scope (Reading token from Cache using token signature). Parent=[S2S] Getting token from STS and setting Thread Identity 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.42  w3wp.exe (0x1B34)                        0x0844 SharePoint Foundation          Monitoring                     b4ly Medium   Leaving Monitored Scope: (Reading token from Cache using token signature) Execution Time=0.903758365713731; CPU Milliseconds=0; SQL Query Count=0; Parent=[S2S] Getting token from STS and setting Thread Identity 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.42  w3wp.exe (0x1B34)                        0x0844 SharePoint Foundation          Application Authentication     ajwpx Medium   SPApplicationAuthenticationModule: Failed to build cache key for user  12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.42  w3wp.exe (0x1B34)                        0x0844 SharePoint Foundation          Topology                       aeayb Medium   SecurityTokenServiceSendRequest: RemoteAddress: 'http://localhost:32843/SecurityTokenServiceApplication/securitytoken.svc' Channel: 'Microsoft.IdentityModel.Protocols.WSTrust.IWSTrustChannelContract' Action: 'http://docs.oasis-open.org/ws-sx/ws-trust/200512/RST/Issue' MessageId: 'urn:uuid:724cb918-aa2d-4bf6-9344-4ec96832494f' 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.42  w3wp.exe (0x191C)                        0x1948 SharePoint Foundation          Topology                       aeax9 Medium   SecurityTokenServiceReceiveRequest: LocalAddress: 'http://WFE1.contoso.com:32843/SecurityTokenServiceApplication/securitytoken.svc' Channel: 'System.ServiceModel.Channels.ServiceChannel' Action: 'http://docs.oasis-open.org/ws-sx/ws-trust/200512/RST/Issue' MessageId: 'urn:uuid:724cb918-aa2d-4bf6-9344-4ec96832494f' 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.42  w3wp.exe (0x191C)                        0x1948 SharePoint Foundation          Monitoring                     nasq Medium   Entering Monitored Scope (ExecuteSecurityTokenServiceOperationServer). Parent=None 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.42  w3wp.exe (0x191C)                        0x1948 SharePoint Foundation          Claims Authentication          arhor Medium   STS Call: Creating Claims Operations Scope for Applies To Uri: 'https://Sharepoint.contoso.com/sites/wkfltest/_api/web/lists(guid'6c5dd2bd-db15-45ee-aad1-4101763e7a...
02/13/2018 13:05:46.42  w3wp.exe (0x191C)                        0x1948 SharePoint Foundation          Claims Authentication          arhon Medium   Not creating SPClaimsOperationContext since there is one on the thread already. Uri: 'https://Sharepoint.contoso.com/sites/wkfltest/_api/web/lists(guid'6c5dd2bd-db15-45ee-aad1-4101763e7a...
02/13/2018 13:05:46.43  w3wp.exe (0x191C)                        0x1948 SharePoint Foundation          Claims Authentication          ah25l Medium   Json token issuer is not self issuer. IssuerName: '00000005-0000-0000-c000-000000000000'. 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.43  w3wp.exe (0x191C)                        0x1948 SharePoint Foundation          Claims Authentication          an3dw Medium   GetTokenLifetime: This is an OAuth Request, so we will look into the user identity to figure out the correct token lifetime. 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.43  w3wp.exe (0x191C)                        0x1948 Document Management Server     Reporting                      axzt1 Medium   UPAClaimProvider_GetMappedIdentityClaim Start: My Scenario Start 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.43  w3wp.exe (0x191C)                        0x1948 SharePoint Foundation          User Key                       aysv4 Medium   Current thread identity is claim auth. Result: 'i:0).w|s-1-5-21-4011730907-378038688-2230072918-42788'. 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.43  w3wp.exe (0x191C)                        0x1948 SharePoint Foundation          Authentication Authorization   a7r50 Medium   RunWithElevated:  12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.43  w3wp.exe (0x191C)                        0x1948 Document Management Server     Reporting                      axzud Medium   UPAClaimProvider_GetSingleUserProfileFromClaimsList Start: My Scenario Start 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.43  w3wp.exe (0x191C)                        0x1BA0 SharePoint Portal Server       User Profiles                  ajk33 Medium   UserProfileProperty_WCFLogging :: Begin UserProfileApplication.GetProperties  
02/13/2018 13:05:46.43  w3wp.exe (0x191C)                        0x1948 SharePoint Foundation          Monitoring                     nasq Medium   Entering Monitored Scope (UserProfile.RetrieveUserFromCache). Parent=Executing the user mapping operation in GetMappedIdentityClaim() 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.43  w3wp.exe (0x191C)                        0x1948 Document Management Server     Reporting                      avv31 Medium   GetUserProfile_RetrieveUser_Cache Start: My Scenario Start 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.43  w3wp.exe (0x191C)                        0x1948 SharePoint Portal Server       User Profiles                  ajk39 Medium   UserProfileDBCache_WCFLogging::Begin ProfileDBCacheServiceClient.GetUserData.ExecuteOnChannel 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.43  w3wp.exe (0x191C)                        0x1948 SharePoint Portal Server       User Profiles                  arkm4 Medium   ChannelInvoke::GetUserData::1 -- Executing code block on endpoint [http://WFE1:32843/1a7b3a1347bb485d8c910521ad301c96/ProfileDBCacheService.svc]. 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.43  w3wp.exe (0x191C)                        0x1948 SharePoint Foundation          Topology                       e5mc Medium   WcfSendRequest: RemoteAddress: 'http://WFE1:32843/1a7b3a1347bb485d8c910521ad301c96/ProfileDBCacheService.svc' Channel: 'Microsoft.Office.Server.UserProfiles.IProfileDBCacheService' Action: 'http://Microsoft.Office.Server.UserProfiles/GetUserData' MessageId: 'urn:uuid:6f62253f-3101-4d1b-8134-c188be0ac4ba' 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.43  w3wp.exe (0x1BC0)                        0x130C SharePoint Foundation          Monitoring                     nasq Medium   Entering Monitored Scope (ExecuteWcfServerOperation (http://WFE1.contoso.com:32843/1a7b3a1347bb485d8c910521ad301c96/ProfileDBCacheService.svc)). Parent=None  
02/13/2018 13:05:46.43  w3wp.exe (0x1BC0)                        0x130C SharePoint Foundation          Topology                       e5mb Medium   WcfReceiveRequest: LocalAddress: 'http://WFE1.contoso.com:32843/1a7b3a1347bb485d8c910521ad301c96/ProfileDBCacheService.svc' Channel: 'System.ServiceModel.Channels.ServiceChannel' Action: 'http://Microsoft.Office.Server.UserProfiles/GetUserData' MessageId: 'urn:uuid:6f62253f-3101-4d1b-8134-c188be0ac4ba' 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.43  w3wp.exe (0x1BC0)                        0x130C SharePoint Portal Server       User Profiles                  cnu0 Medium   UserProfileDBCache: PartitionId: 0c37852b-34d0-418e-91c6-2ac25af4be5b. Retrieved record from cache for search key RecordID 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.43  w3wp.exe (0x1BC0)                        0x130C SharePoint Foundation          Micro Trace                    uls4 Medium   Micro Trace Tags: 0 nasq,0 e5mb,0 cnu0 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.43  w3wp.exe (0x1BC0)                        0x130C SharePoint Foundation          Monitoring                     b4ly Medium   Leaving Monitored Scope: (ExecuteWcfServerOperation (http://WFE1.contoso.com:32843/1a7b3a1347bb485d8c910521ad301c96/ProfileDBCacheService.svc)) Execution Time=0.382592596739938; CPU Milliseconds=0; SQL Query Count=0; Parent=None 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.43  w3wp.exe (0x191C)                        0x1948 SharePoint Portal Server       User Profiles                  arkm5 Medium   ChannelInvoke::GetUserData::1 -- Code block executed on endpoint [http://WFE1:32843/1a7b3a1347bb485d8c910521ad301c96/ProfileDBCacheService.svc]. CurrentElapsedTime(ms): 5 TotalElapsedTime(ms): 5 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.43  w3wp.exe (0x191C)                        0x1948 SharePoint Portal Server       User Profiles                  ajk4a Medium   UserProfileDBCache_WCFLogging::End ProfileDBCacheServiceClient.GetUserData.ExecuteOnChannel 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.43  w3wp.exe (0x191C)                        0x1948 Document Management Server     Reporting                      avv32 Medium   GetUserProfile_RetrieveUser_Cache Success: My Scenario Success 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.43  w3wp.exe (0x191C)                        0x1948 SharePoint Foundation          Monitoring                     b4ly Medium   Leaving Monitored Scope: (UserProfile.RetrieveUserFromCache) Execution Time=6.41869067481869; CPU Milliseconds=3; SQL Query Count=0; Parent=Executing the user mapping operation in GetMappedIdentityClaim() 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.43  w3wp.exe (0x191C)                        0x1948 SharePoint Portal Server       User Profiles                  ajk39 Medium   UserProfileDBCache_WCFLogging::Begin ProfileDBCacheServiceClient.GetUserData.ExecuteOnChannel 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.43  w3wp.exe (0x191C)                        0x1948 SharePoint Portal Server       User Profiles                  arkm4 Medium   ChannelInvoke::GetUserData::1 -- Executing code block on endpoint [http://WFE1:32843/1a7b3a1347bb485d8c910521ad301c96/ProfileDBCacheService.svc]. 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.43  w3wp.exe (0x191C)                        0x1948 SharePoint Foundation          Topology                       e5mc Medium   WcfSendRequest: RemoteAddress: 'http://WFE1:32843/1a7b3a1347bb485d8c910521ad301c96/ProfileDBCacheService.svc' Channel: 'Microsoft.Office.Server.UserProfiles.IProfileDBCacheService' Action: 'http://Microsoft.Office.Server.UserProfiles/GetUserData' MessageId: 'urn:uuid:54377f8b-37b5-47dd-bd00-1d9c563f5eee' 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.43  w3wp.exe (0x1BC0)                        0x0DA8 SharePoint Foundation          Monitoring                     nasq Medium   Entering Monitored Scope (ExecuteWcfServerOperation (http://WFE1.contoso.com:32843/1a7b3a1347bb485d8c910521ad301c96/ProfileDBCacheService.svc)). Parent=None  
02/13/2018 13:05:46.43  w3wp.exe (0x1BC0)                        0x0DA8 SharePoint Foundation          Topology                       e5mb Medium   WcfReceiveRequest: LocalAddress: 'http://WFE1.contoso.com:32843/1a7b3a1347bb485d8c910521ad301c96/ProfileDBCacheService.svc' Channel: 'System.ServiceModel.Channels.ServiceChannel' Action: 'http://Microsoft.Office.Server.UserProfiles/GetUserData' MessageId: 'urn:uuid:54377f8b-37b5-47dd-bd00-1d9c563f5eee' 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.43  w3wp.exe (0x1BC0)                        0x0DA8 SharePoint Portal Server       User Profiles                  cnu0 Medium   UserProfileDBCache: PartitionId: 0c37852b-34d0-418e-91c6-2ac25af4be5b. Retrieved record from cache for search key Email 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.43  w3wp.exe (0x1BC0)                        0x0DA8 SharePoint Foundation          Micro Trace                    uls4 Medium   Micro Trace Tags: 0 nasq,0 e5mb,0 cnu0 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.43  w3wp.exe (0x1BC0)                        0x0DA8 SharePoint Foundation          Monitoring                     b4ly Medium   Leaving Monitored Scope: (ExecuteWcfServerOperation (http://WFE1.contoso.com:32843/1a7b3a1347bb485d8c910521ad301c96/ProfileDBCacheService.svc)) Execution Time=0.319604791179094; CPU Milliseconds=0; SQL Query Count=0; Parent=None 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.43  w3wp.exe (0x191C)                        0x1948 SharePoint Portal Server       User Profiles                  arkm5 Medium   ChannelInvoke::GetUserData::1 -- Code block executed on endpoint [http://WFE1:32843/1a7b3a1347bb485d8c910521ad301c96/ProfileDBCacheService.svc]. CurrentElapsedTime(ms): 4 TotalElapsedTime(ms): 4 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.43  w3wp.exe (0x191C)                        0x1948 SharePoint Portal Server       User Profiles                  ajk4a Medium   UserProfileDBCache_WCFLogging::End ProfileDBCacheServiceClient.GetUserData.ExecuteOnChannel 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.43  w3wp.exe (0x191C)                        0x1948 SharePoint Foundation          Monitoring                     nasq Medium   Entering Monitored Scope (UserProfile.RetrieveUserFromCache). Parent=Executing the user mapping operation in GetMappedIdentityClaim() 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.43  w3wp.exe (0x191C)                        0x1948 Document Management Server     Reporting                      avv31 Medium   GetUserProfile_RetrieveUser_Cache Start: My Scenario Start 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.43  w3wp.exe (0x191C)                        0x1948 SharePoint Portal Server       User Profiles                  ajk39 Medium   UserProfileDBCache_WCFLogging::Begin ProfileDBCacheServiceClient.GetUserData.ExecuteOnChannel 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.43  w3wp.exe (0x191C)                        0x1948 SharePoint Portal Server       User Profiles                  arkm4 Medium   ChannelInvoke::GetUserData::1 -- Executing code block on endpoint [http://WFE1:32843/1a7b3a1347bb485d8c910521ad301c96/ProfileDBCacheService.svc]. 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.43  w3wp.exe (0x191C)                        0x1948 SharePoint Foundation          Topology                       e5mc Medium   WcfSendRequest: RemoteAddress: 'http://WFE1:32843/1a7b3a1347bb485d8c910521ad301c96/ProfileDBCacheService.svc' Channel: 'Microsoft.Office.Server.UserProfiles.IProfileDBCacheService' Action: 'http://Microsoft.Office.Server.UserProfiles/GetUserData' MessageId: 'urn:uuid:741d20b7-7689-40a9-bfc0-1b320604893e' 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.45  w3wp.exe (0x1BC0)                        0x130C SharePoint Foundation          Monitoring                     nasq Medium   Entering Monitored Scope (ExecuteWcfServerOperation (http://WFE1.contoso.com:32843/1a7b3a1347bb485d8c910521ad301c96/ProfileDBCacheService.svc)). Parent=None  
02/13/2018 13:05:46.45  w3wp.exe (0x1BC0)                        0x130C SharePoint Foundation          Topology                       e5mb Medium   WcfReceiveRequest: LocalAddress: 'http://WFE1.contoso.com:32843/1a7b3a1347bb485d8c910521ad301c96/ProfileDBCacheService.svc' Channel: 'System.ServiceModel.Channels.ServiceChannel' Action: 'http://Microsoft.Office.Server.UserProfiles/GetUserData' MessageId: 'urn:uuid:741d20b7-7689-40a9-bfc0-1b320604893e' 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.45  w3wp.exe (0x1BC0)                        0x130C SharePoint Portal Server       User Profiles                  cnu0 Medium   UserProfileDBCache: PartitionId: 0c37852b-34d0-418e-91c6-2ac25af4be5b. Retrieved record from cache for search key SID 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.45  w3wp.exe (0x1BC0)                        0x130C SharePoint Foundation          Micro Trace                    uls4 Medium   Micro Trace Tags: 0 nasq,0 e5mb,0 cnu0 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.45  w3wp.exe (0x1BC0)                        0x130C SharePoint Foundation          Monitoring                     b4ly Medium   Leaving Monitored Scope: (ExecuteWcfServerOperation (http://WFE1.contoso.com:32843/1a7b3a1347bb485d8c910521ad301c96/ProfileDBCacheService.svc)) Execution Time=0.313539298791754; CPU Milliseconds=0; SQL Query Count=0; Parent=None 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.45  w3wp.exe (0x191C)                        0x1948 SharePoint Portal Server       User Profiles                  arkm5 Medium   ChannelInvoke::GetUserData::1 -- Code block executed on endpoint [http://WFE1:32843/1a7b3a1347bb485d8c910521ad301c96/ProfileDBCacheService.svc]. CurrentElapsedTime(ms): 3 TotalElapsedTime(ms): 3 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.45  w3wp.exe (0x191C)                        0x1948 SharePoint Portal Server       User Profiles                  ajk4a Medium   UserProfileDBCache_WCFLogging::End ProfileDBCacheServiceClient.GetUserData.ExecuteOnChannel 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.45  w3wp.exe (0x191C)                        0x1948 Document Management Server     Reporting                      avv32 Medium   GetUserProfile_RetrieveUser_Cache Success: My Scenario Success 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.45  w3wp.exe (0x191C)                        0x1948 SharePoint Foundation          Monitoring                     b4ly Medium   Leaving Monitored Scope: (UserProfile.RetrieveUserFromCache) Execution Time=4.790805833324; CPU Milliseconds=2; SQL Query Count=0; Parent=Executing the user mapping operation in GetMappedIdentityClaim() 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.45  w3wp.exe (0x191C)                        0x1948 Document Management Server     Reporting                      axzue Medium   UPAClaimProvider_GetSingleUserProfileFromClaimsList Success: My Scenario Success 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.45  w3wp.exe (0x191C)                        0x1948 Document Management Server     Reporting                      axzt2 Medium   UPAClaimProvider_GetMappedIdentityClaim Success: My Scenario Success 12df4c15-6418-1362-98a7-d7a9c682eb70
02/13/2018 13:05:46.45  w3wp.exe (0x191C)                        0x1948 SharePoint Foundation          Claims Authentication          bblx0 Unexpected SPSecurityTokenServiceManager!EnsureSharePointLogonRequestClaims: InputIdentity doesn't conatin a PrimarySid claim. 12df4c15-6418-1362-98a7-d7a9c682eb70

3 Replies

I'm experiencing the same issue. Were you able to find a resolution? 

Sadly no, other things have taken over priority and I never got back to this.

I'm experiencing the same issue. Were you able to find a resolution?