Error: Event ID 6398 – FeedCacheService: Failed to Decrypt data..

28.4.2017    |    komentáře   komentářů: 0

The error ‘Event ID 6398 – FeedCacheService: Failed to Decrypt data..’ is an error in the Distributed Cache (AppFabric 1.1)service. It occurs when the ‘Feed Cache Repopulation Job”, or “Feed Cache Full Repopulation Job“.

Event ID 6398 – Error details

Log Name: Application
Source: SharePoint Foundation
Event ID: 6398
Level: Critical
User: “SP Farm Account”
Message: The Execute method of job definition Microsoft.Office.Server.UserProfiles.FeedCacheRepopulationJob (“Corelation ID”) threw an exception. More information is included below.

Unexpected exception in FeedCacheService.IsRepopulationNeeded: Failed to Decrypt data… (“Corelation ID”)

Event ID 6398

The error ‘Event ID 6398 – FeedCacheService: Failed to Decrypt data..’ error is therefore directly related to running these timer jobs:

  • User Profile Service Application Proxy – Feed Cache Repopulation Job
  • User Profile Service Application Proxy – Feed Cache Full Repopulation Job

Job History Feed Cache Failed

These two jobs move/save ‘social’ activities and comments from Distributed Cache memory (AppFabric 1.1) to the User Profile Service databases.

A closer look at the ULS logs reveals two interesting messages:

  1. Padding is invalid and cannot be removed
  2. Unable to decrypt using secret key

In the case of ‘Padding is invalid and cannot be removed’, this could be an incorrect message that appears when attempting to use the ‘ConvertTo-SecureString’ function, which could also lead to the second message, ‘Unable to decrypt using secret key’, indicating that the security key used was not valid.

Unfortunately, I still have not found the exact cause, but a series of steps eventually helped me get rid of this error.

Event ID 6398 – Resolving the error

Distributed Cache – Checking the backgroundGC key

Check that the Distributed Cache configuration file contains the <add key="backgroundGC" value="true"/> entry.

File location: C:\Program Files\AppFabric 1.1 for Windows Server\DistributedCacheService.exe.CONFIG

 <appSettings>
 <add key="backgroundGC" value="true"/>
 </appSettings>

Distributed Cache - appSettings backgroundGC

Secure Store – Refresh Key

Secure Store

In the Secure Store service application, select ‘Refresh Key’. This step requires the passphrase key, but otherwise it cannot do any harm.

Distributed Cache – Restarting the cluster

The first attempt to resolve the problem should be to restart the Distributed Cache cluster, including all its members.

You can do this for the entire cluster with the following PowerShell command:

Use-CacheCluster
Restart-CacheCluster

Distributed Cache – Removing and re-adding the service

If restarting the cluster does not help, remove Distributed Cache from the affected server (this stops and disables AppFabric Caching Service), restart the server, and then add Distributed Cache to it again.

  1. Remove Distributed Cache from the affected server 
    Remove-SPDistributedCacheServiceInstance
  2. Restart the affected server
  3. If Distributed Cache runs on multiple servers, restart the cluster from one of them (see the step above)
  4. Add Distributed Cache 
    Add-SPDistributedCacheServiceInstance

Event ID 6398 – ULS log

Timestamp              	Process                                 	TID   	Area                          	Category                      	EventID	Level     	Message 	Correlation
04/28/2017 08:30:31.94 	OWSTIMER.EXE (xxxx:0x068C)     	0x06B0	SharePoint Foundation         	Logging Correlation Data      	xmnv	Medium	Name=Timer Job User Profile Service Application Proxy_FeedCacheRepopulationJob	dd56ec9d-ad30-b097-f5c9-a3932a16b94a
04/28/2017 08:30:31.94 	OWSTIMER.EXE (xxxx:0x068C)     	0x06B0	SharePoint Portal Server      	Feed Cache                    	aobdn	Medium	FeedCache repopulation job begins	dd56ec9d-ad30-b097-f5c9-a3932a16b94a
04/28/2017 08:30:31.94 	OWSTIMER.EXE (xxxx:0x068C)     	0x06B0	SharePoint Portal Server      	User Profiles                 	arkm4	Medium	ChannelInvoke::IsRepopulationNeeded::1 -- Executing code block on endpoint [http://xxxx:32843/5372e251e8a8475a90cc959dba17a0e3/FeedCacheService.svc].	dd56ec9d-ad30-b097-f5c9-a3932a16b94a
04/28/2017 08:30:31.94 	OWSTIMER.EXE (xxxx:0x068C)     	0x06B0	SharePoint Foundation         	Topology                      	e5mc	Medium	WcfSendRequest: RemoteAddress: 'http://xxxx:32843/5372e251e8a8475a90cc959dba17a0e3/FeedCacheService.svc' Channel: 'Microsoft.Office.Server.UserProfiles.IFeedCacheService' Action: 'http://Microsoft.Office.Server.UserProfiles/IsRepopulationNeeded' MessageId: 'urn:uuid:8a3e72ac-f896-4c85-80a9-1f7ee12b8826'	dd56ec9d-ad30-b097-f5c9-a3932a16b94a
04/28/2017 08:30:31.96 	w3wp.exe (xxxx:0x03C4)         	0x0D7C	SharePoint Foundation         	Topology                      	e5mb	Medium	WcfReceiveRequest: LocalAddress: 'http://xxxx.local:32843/5372e251e8a8475a90cc959dba17a0e3/FeedCacheService.svc' Channel: 'System.ServiceModel.Channels.ServiceChannel' Action: 'http://Microsoft.Office.Server.UserProfiles/IsRepopulationNeeded' MessageId: 'urn:uuid:8a3e72ac-f896-4c85-80a9-1f7ee12b8826'	dd56ec9d-ad30-b097-f5c9-a3932a16b94a
04/28/2017 08:30:31.96 	w3wp.exe (xxxx:0x03C4)         	0x0D7C	SharePoint Foundation         	Monitoring                    	nasq	Medium	Entering Monitored Scope (FeedCacheService.IsRepopulationNeeded). Parent=ExecuteWcfServerOperation (http://xxxx.local:32843/5372e251e8a8475a90cc959dba17a0e3/FeedCacheService.svc)	dd56ec9d-ad30-b097-f5c9-a3932a16b94a
04/28/2017 08:30:31.96 	w3wp.exe (xxxx:0x03C4)         	0x0D7C	SharePoint Foundation         	Monitoring                    	nasq	Medium	Entering Monitored Scope (FeedCacheImplementation.IsRepopulationNeeded). Parent=FeedCacheService.IsRepopulationNeeded	dd56ec9d-ad30-b097-f5c9-a3932a16b94a
04/28/2017 08:30:31.96 	w3wp.exe (xxxx:0x03C4)         	0x0D7C	SharePoint Foundation         	Monitoring                    	nasq	Medium	Entering Monitored Scope (FeedCacheDataCacheWrapper.GetObject). Parent=FeedCacheImplementation.IsRepopulationNeeded	dd56ec9d-ad30-b097-f5c9-a3932a16b94a
04/28/2017 08:30:31.96 	w3wp.exe (xxxx:0x03C4)         	0x0D7C	SharePoint Server             	Distributed Cache             	aa6e5	Unexpected	Unexpected error in Decrypt - Exception 'System.Security.Cryptography.CryptographicException: Padding is invalid and cannot be removed.     at System.Security.Cryptography.CapiSymmetricAlgorithm.DepadBlock(Byte[] block, Int32 offset, Int32 count)     at System.Security.Cryptography.CapiSymmetricAlgorithm.TransformFinalBlock(Byte[] inputBuffer, Int32 inputOffset, Int32 inputCount)     at System.Security.Cryptography.CryptoStream.FlushFinalBlock()     at System.Security.Cryptography.CryptoStream.Dispose(Boolean disposing)     at System.IO.Stream.Close()     at Microsoft.Office.Server.DistributedCaching.SPDistributedCacheUtils.Transform(Byte[] buffer, ICryptoTransform transformer)     at Microsoft.Office.Server.DistributedCaching.SPDistributedCacheUtils.Transform(Byte[] secretKey, Byte[] buff...	dd56ec9d-ad30-b097-f5c9-a3932a16b94a
04/28/2017 08:30:31.96*	w3wp.exe (xxxx:0x03C4)         	0x0D7C	SharePoint Server             	Distributed Cache             	aa6e5	Unexpected	...er, Boolean encrypt)     at Microsoft.Office.Server.DistributedCaching.SPDistributedCacheUtils.Decrypt(Byte[] secretKey, Byte[] buffer)'.	dd56ec9d-ad30-b097-f5c9-a3932a16b94a
04/28/2017 08:30:31.96 	w3wp.exe (xxxx:0x03C4)         	0x0D7C	SharePoint Server             	Distributed Cache             	a7l3j	High	Unable to decrypt using secret key. Exception 'Microsoft.Office.Server.DistributedCaching.SPDistributedCachedObjectDecryptionFailedException: Failed to Decrypt data.     at Microsoft.Office.Server.DistributedCaching.SPDistributedCacheUtils.Decrypt(Byte[] secretKey, Byte[] buffer)     at Microsoft.Office.Server.DistributedCaching.SPDistributedCacheUtils.PostProcessData(Byte[] secretKey, Object cachedObject, Boolean bDecrptyData, SPDistributedCacheTelemetryData teleData)'.	dd56ec9d-ad30-b097-f5c9-a3932a16b94a
04/28/2017 08:30:31.96 	w3wp.exe (xxxx:0x03C4)         	0x0D7C	SharePoint Server             	Distributed Cache             	a7l3m	Unexpected	Unable to PostProcessData - Exception 'Microsoft.Office.Server.DistributedCaching.SPDistributedCachedObjectDecryptionFailedException: Failed to Decrypt data.     at Microsoft.Office.Server.DistributedCaching.SPDistributedCacheUtils.Decrypt(Byte[] secretKey, Byte[] buffer)     at Microsoft.Office.Server.DistributedCaching.SPDistributedCacheUtils.PostProcessData(Byte[] secretKey, Object cachedObject, Boolean bDecrptyData, SPDistributedCacheTelemetryData teleData)'.	dd56ec9d-ad30-b097-f5c9-a3932a16b94a
04/28/2017 08:30:31.96 	w3wp.exe (xxxx:0x03C4)         	0x0D7C	SharePoint Server             	Distributed Cache             	agyfy	Unexpected	Unexpected error occurred in method 'GetObject' , usage 'FeedCache' - Exception 'Microsoft.Office.Server.DistributedCaching.SPDistributedCachedObjectDecryptionFailedException: Failed to Decrypt data.     at Microsoft.Office.Server.DistributedCaching.SPDistributedCacheUtils.Decrypt(Byte[] secretKey, Byte[] buffer)     at Microsoft.Office.Server.DistributedCaching.SPDistributedCacheUtils.PostProcessData(Byte[] secretKey, Object cachedObject, Boolean bDecrptyData, SPDistributedCacheTelemetryData teleData)     at Microsoft.Office.Server.DistributedCaching.SPDistributedCache.GetObject(String key, String regionName)'.	dd56ec9d-ad30-b097-f5c9-a3932a16b94a
04/28/2017 08:30:31.96 	w3wp.exe (xxxx:0x03C4)         	0x0D7C	SharePoint Foundation         	Monitoring                    	b4ly	Medium	Leaving Monitored Scope: (FeedCacheDataCacheWrapper.GetObject) Execution Time=2.46148602685537; CPU Milliseconds=1; SQL Query Count=0; Parent=FeedCacheImplementation.IsRepopulationNeeded	dd56ec9d-ad30-b097-f5c9-a3932a16b94a
04/28/2017 08:30:31.96 	w3wp.exe (xxxx:0x03C4)         	0x0D7C	SharePoint Portal Server      	Feed Cache                    	afr68	High	FeedCacheImplementation.IsRepopulationNeeded() - Unexpected exception while trying to check is repopulation is needed for a given UPA: Microsoft.Office.Server.DistributedCaching.SPDistributedCachedObjectDecryptionFailedException: Failed to Decrypt data.     at Microsoft.Office.Server.DistributedCaching.SPDistributedCache.GetObject(String key, String regionName)     at Microsoft.Office.Server.FeedCache.FeedCacheDataCacheWrapper.GetObject(String key, String regionName)     at Microsoft.Office.Server.FeedCache.FeedCacheImplementation.IsRepopulationNeeded(Guid callerID)	dd56ec9d-ad30-b097-f5c9-a3932a16b94a
04/28/2017 08:30:31.96 	w3wp.exe (xxxx:0x03C4)         	0x0D7C	SharePoint Foundation         	Monitoring                    	b4ly	Medium	Leaving Monitored Scope: (FeedCacheImplementation.IsRepopulationNeeded) Execution Time=2.91224163964973; CPU Milliseconds=2; SQL Query Count=0; Parent=FeedCacheService.IsRepopulationNeeded	dd56ec9d-ad30-b097-f5c9-a3932a16b94a
04/28/2017 08:30:31.96 	w3wp.exe (xxxx:0x03C4)         	0x0D7C	SharePoint Portal Server      	Feed Cache                    	afr7r	Unexpected	Unexpected exception in FeedCacheService.IsRepopulationNeeded: Failed to Decrypt data..:    at Microsoft.Office.Server.DistributedCaching.SPDistributedCache.GetObject(String key, String regionName)     at Microsoft.Office.Server.FeedCache.FeedCacheDataCacheWrapper.GetObject(String key, String regionName)     at Microsoft.Office.Server.FeedCache.FeedCacheImplementation.IsRepopulationNeeded(Guid callerID)     at Microsoft.Office.Server.UserProfiles.FeedCacheService.Microsoft.Office.Server.UserProfiles.IFeedCacheService.IsRepopulationNeeded(Guid callerID)	dd56ec9d-ad30-b097-f5c9-a3932a16b94a
04/28/2017 08:30:31.97 	w3wp.exe (xxxx:0x03C4)         	0x0D7C	SharePoint Foundation         	Monitoring                    	b4ly	Medium	Leaving Monitored Scope: (FeedCacheService.IsRepopulationNeeded) Execution Time=3.44436234214125; CPU Milliseconds=2; SQL Query Count=0; Parent=ExecuteWcfServerOperation (http://xxxx:32843/5372e251e8a8475a90cc959dba17a0e3/FeedCacheService.svc)	dd56ec9d-ad30-b097-f5c9-a3932a16b94a
04/28/2017 08:30:31.97 	w3wp.exe (xxxx:0x03C4)         	0x0D7C	SharePoint Foundation         	Micro Trace                   	uls4	Medium	Micro Trace Tags: 0 nasq,0 e5mb,0 nasq,0 nasq,0 nasq,1 aa6e5,0 a7l3j,0 a7l3m,0 agyfy,0 b4ly,0 afr68,0 b4ly,0 afr7r,0 b4ly	dd56ec9d-ad30-b097-f5c9-a3932a16b94a
04/28/2017 08:30:31.97 	w3wp.exe (xxxx:0x03C4)         	0x0D7C	SharePoint Foundation         	Monitoring                    	b4ly	Medium	Leaving Monitored Scope: (ExecuteWcfServerOperation (http://xxxx.local:32843/5372e251e8a8475a90cc959dba17a0e3/FeedCacheService.svc)) Execution Time=4.17336560931627; CPU Milliseconds=3; SQL Query Count=0; Parent=None	dd56ec9d-ad30-b097-f5c9-a3932a16b94a
04/28/2017 08:30:31.97 	OWSTIMER.EXE (xxxx:0x068C)     	0x06B0	SharePoint Portal Server      	User Profiles                 	arkm7	High	ChannelInvoke::IsRepopulationNeeded::1 -- FaultException occurred: [FaultCode=Sender][FaultSubCode=UnspecifiedSubCode] System.ServiceModel.FaultException`1[Microsoft.Office.Server.UserProfiles.FeedCacheFault]: Unexpected exception in FeedCacheService.IsRepopulationNeeded: Failed to Decrypt data.. (Fault Detail is equal to Microsoft.Office.Server.UserProfiles.FeedCacheFault).	dd56ec9d-ad30-b097-f5c9-a3932a16b94a
04/28/2017 08:30:31.97 	OWSTIMER.EXE (xxxx:0x068C)     	0x06B0	SharePoint Portal Server      	Feed Cache                    	adbpm	Unexpected	Exception occured in ExecuteOnChannel: System.ServiceModel.FaultException`1[Microsoft.Office.Server.UserProfiles.FeedCacheFault]: Unexpected exception in FeedCacheService.IsRepopulationNeeded: Failed to Decrypt data.. (Fault Detail is equal to Microsoft.Office.Server.UserProfiles.FeedCacheFault).	dd56ec9d-ad30-b097-f5c9-a3932a16b94a
04/28/2017 08:30:31.97 	OWSTIMER.EXE (xxxx:0x068C)     	0x06B0	SharePoint Foundation         	Timer                         	6398	Critical	The Execute method of job definition Microsoft.Office.Server.UserProfiles.FeedCacheRepopulationJob (ID bc0d6236-eaba-4815-a7a6-feba096b65dd) threw an exception. More information is included below.  Unexpected exception in FeedCacheService.IsRepopulationNeeded: Failed to Decrypt data... (Correlation=dd56ec9d-ad30-b097-f5c9-a3932a16b94a)	dd56ec9d-ad30-b097-f5c9-a3932a16b94a
04/28/2017 08:30:31.97 	OWSTIMER.EXE (xxxx:0x068C)     	0x06B0	SharePoint Foundation         	Timer                         	72ae	Unexpected	Exception stack trace:    at Microsoft.Office.Server.UserProfiles.FeedCacheServiceClient.ExecuteOnChannel(String operationName, CodeBlock codeBlock)     at Microsoft.Office.Server.UserProfiles.FeedCacheServiceClient.IsRepopulationNeeded(Guid callerID)     at Microsoft.Office.Server.UserProfiles.LMTRepopulationJob.IsRepopulationNeeded(UserProfileApplicationProxy proxy, SPPersistedObject parent)     at Microsoft.Office.Server.UserProfiles.FeedCacheRepopulationJob.ShouldRunJob()     at Microsoft.Office.Server.UserProfiles.FeedCacheRepopulationJob.Execute()     at Microsoft.SharePoint.Administration.SPTimerJobInvokeInternal.Invoke(SPJobDefinition jd, Guid targetInstanceId, Boolean isTimerService, Int32& result)	dd56ec9d-ad30-b097-f5c9-a3932a16b94a
04/28/2017 08:30:31.97 	OWSTIMER.EXE (xxxx:0x068C)     	0x06B0	SharePoint Foundation         	General                       	a479h	Medium	SMART API does not exist or Job is null. Skip alerting.	dd56ec9d-ad30-b097-f5c9-a3932a16b94a
04/28/2017 08:30:31.97 	OWSTIMER.EXE (xxxx:0x068C)     	0x06B0	SharePoint Foundation         	Timer                         	an9i8	High	Completed processing of timer job [User Profile Service Application Proxy_FeedCacheRepopulationJob] with lock type [Job] against target instance [bc0d6236-eaba-4815-a7a6-feba096b65dd] [FeedCacheRepopulationJob Name=User Profile Service Application Proxy_FeedCacheRepopulationJob]. Start time: [04/28/2017 06:30:31]. Duration: [00:00:00.0309694]. Status result: [Failed]. Status ressage (if any): [Unexpected exception in FeedCacheService.IsRepopulationNeeded: Failed to Decrypt data... (Correlation=dd56ec9d-ad30-b097-f5c9-a3932a16b94a)].	dd56ec9d-ad30-b097-f5c9-a3932a16b94a
04/28/2017 08:30:31.97 	OWSTIMER.EXE (xxxx:0x068C)     	0x06B0	SharePoint Foundation         	Monitoring                    	b4ly	Medium	Leaving Monitored Scope: (Timer Job User Profile Service Application Proxy_FeedCacheRepopulationJob) Execution Time=32.8059851182203; CPU Milliseconds=8; SQL Query Count=3; Parent=None	dd56ec9d-ad30-b097-f5c9-a3932a16b94a

Komentáře