none
Logs are not getting saved in Event Store under Usage Analytics

    Question


  • We see that the life time views in one of our SharePoint farm is not rendering the count, so while investigating the issue, noticed that the Usage Analytics were not getting saved.
     
    The last time the data got saved in analytics folder was more than 6 months ago,

    SearchServer2\Analytics_bcd0207d-7b38-432d-aee2-082fe1fe9951\EventStore\20180503\logs are generated, but no data under
    SearchServer2\Analytics_GUID\AE\AnalyticsProcessingComponent1\UsageAnalytics

    I confirm the below jobs ran to success:
    Microsoft SharePoint Foundation Usage Data Import
    Microsoft SharePoint Foundation Usage Data Processing
    Analytics Timer Job for Search Service Application Search Service Application


    I verified if the Usage Analytics job(the one that runs at 1AM) ran, and notice it failed

    PS C:\Users\ZZZZZ> $tj.GetAnalysisInfo()

    Name                                : UsageAnalytics
    State                               : Failed
    Progress                            : 0
    RunningTasks                        : {}
    FailedTasks                         : {}
    ActiveAnalyticsProcessingComponents : {AnalyticsProcessingComponent1Server1, AnalyticsProcessingComponent2Server2}
    CacheClear                          : True
    CurrentRunStartedTime               :
    LastRunCompletedStartTime           : 9/5/2017 1:00:01 AM
    LastRunCompletedTime                : 9/5/2017 1:10:37 AM
    LastRunCompletedDurationTime        : 00:10:36.3161429
    LastRunFailedStartTime              : 9/14/2017 8:00:00 PM
    LastRunFailedTime                   : 9/14/2017 8:40:40 PM
    LastRunFailedDurationTime           : 00:40:40.4214577
    LastRunFailedErrorMsg               : Target Microsoft.UsageAnalyticsReportingAPIDumperFlow failed too many times: Flow
                                          UsageAnalytics-Microsoft.UsageAnalyticsReportingAPIDumperFlow failed on node AnalyticsProcessingComponent1:
                                          Evaluation failure. An evaluation thread threw an exception. (Exception type:
                                          Microsoft.Ceres.Evaluation.DataModel.EvaluationException. Exception message: FileWriter: One or more output
                                          files could not be opened)
    LastRunCompleted                    : False
    CompletedRuns                       : 219
    FailedRuns                          : 41
    ClearAnalysisCount                  : 16505
    SubState                            : None
    CurrentRunRestarts                  :
    CurrentRunDuration                  :
    CurrentRunTotalTasks                :
    CurrentRunCompletedTasks            :

    So, I attempted to Disable and Enable the timer job,

    PS C:\Users\ZZZZZ> $tj = Get-SPTimerJob -Type Microsoft.Office.Server.Search.Analytics.UsageAnalyticsJobDefinition
    PS C:\Users\ZZZZZ> $tj.DisableTimerjobSchedule()
    PS C:\Users\ZZZZZ> $tj.StartAnalysis()
    PS C:\Users\ZZZZZ> $tj.EnableTimerjobSchedule()

    I ran the command again to check if the timer job ran to success, but failed again with same message.
    LastRunFailedErrorMsg               : Target Microsoft.UsageAnalyticsReportingAPIDumperFlow failed too many times: Flow
                                          UsageAnalytics-Microsoft.UsageAnalyticsReportingAPIDumperFlow failed on node AnalyticsProcessingComponent1:
                                          Evaluation failure. An evaluation thread threw an exception. (Exception type:
                                          Microsoft.Ceres.Evaluation.DataModel.EvaluationException. Exception message: FileWriter: One or more output
                                          files could not be opened)


    I notice this in the ULS logs:

    AnalyticsEventStore.GetFileList: eventTypeId = -1

    Name=Task: SessionManager.PerformOngoingRequestDepartures 6b6b4445-521c-0002-9445-b67b6269e89e
    05/03/2018 13:26:22.77  PowerShell.exe (0x6D64)                  0x6C84 SharePoint Server Search       Analytics                      ad9k0 Medium   AnalyticsTimer: Analytics Timer CloseFileTimer created successfully. 72025bae-97a8-0001-13db-1d73a897d301
    05/03/2018 13:26:22.77  PowerShell.exe (0x6D64)                  0x6C84 SharePoint Server Search       Analytics                      ad9k1 Medium   AnalyticsTimer: Analytics Timer CloseFileTimer started successfully. It will run in 2917 seconds 72025bae-97a8-0001-13db-1d73a897d301
    05/03/2018 13:26:22.77  PowerShell.exe (0x6D64)                  0x6C84 SharePoint Server Search       Analytics                      ag7hi Medium   AnalyticsEventStore.GetFiles begin: eventTypeId = -1, time = 05/03/2018 13:26:22. 72025bae-97a8-0001-13db-1d73a897d301
    05/03/2018 13:26:22.78  PowerShell.exe (0x6D64)                  0x6C84 SharePoint Server Search       Analytics                      ag7hj Medium   AnalyticsEventStore.AddFilesToList file added:  Server2\Analytics_bcd0207d-7b38-432d-aee2-082fe1fe9951\EventStore\20180503\1_2018050313_Server2.log. 72025bae-97a8-0001-13db-1d73a897d301
    05/03/2018 13:26:22.78  PowerShell.exe (0x6D64)                  0x6C84 SharePoint Server Search       Analytics                      ag7hj Medium   AnalyticsEventStore.AddFilesToList file added:  Server2\Analytics_bcd0207d-7b38-432d-aee2-082fe1fe9951\EventStore\20180503\1_2018050313_Server2.log. 72025bae-97a8-0001-13db-1d73a897d301
    05/03/2018 13:26:22.78  PowerShell.exe (0x6D64)                  0x6C84 SharePoint Server Search       Analytics                      ag7hj Medium   AnalyticsEventStore.AddFilesToList file added: Server2\Analytics_bcd0207d-7b38-432d-aee2-082fe1fe9951\EventStore\20180503\1_2018050313_Server2.log. 72025bae-97a8-0001-13db-1d73a897d301
    05/03/2018 13:26:22.81  PowerShell.exe (0x6D64)                  0x6C84 SharePoint Server              Database                       abihh High     The scale out database mappings cache is getting refreshed for service id 890cf520-36e4-4d8a-8ec1-eaf4e2b49095. 72025bae-97a8-0001-13db-1d73a897d301
    05/03/2018 13:26:22.83  PowerShell.exe (0x6D64)                  0x6C84 SharePoint Server Search       Analytics                      ad4bl High     SearchServiceApplication (SearchAnalyticsReportingDatabase) GetScaleOutDatabases 72025bae-97a8-0001-13db-1d73a897d301
    05/03/2018 13:26:22.83  PowerShell.exe (0x6D64)                  0x6C84 SharePoint Server              Database                       afjqz Medium   The following range is retrieved for database Search_AnalyticsReportingStore while constructing the database map: Range Start: 00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00, Range End: NULL, Lower Sub-Range Mode: ReadWrite, Lower Sub-Range Point NULL, Upper Sub-Range Mode: ReadWrite, Upper Sub-Range Point: NULL. 72025bae-97a8-0001-13db-1d73a897d301
    05/03/2018 13:26:22.84  PowerShell.exe (0x6D64)                  0x6C84 SharePoint Server              Database                       abihi High     The scale out database mappings cache has been refreshed for service id 890cf520-36e4-4d8a-8ec1-eaf4e2b49095. The new mappings are as follows: For database Data Source=SP_XXX;Initial Catalog=Search_AnalyticsReportingStore;Integrated Security=True;Enlist=False;Pooling=True;Min Pool Size=0;Max Pool Size=100;Connect Timeout=15: range start 00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00, range end NULL. 72025bae-97a8-0001-13db-1d73a897d301
    05/03/2018 13:26:22.87  PowerShell.exe (0x6D64)                  0x6C84 Search                         Usage Analytics                afncy High     It's about time to run analysis. 72025bae-97a8-0001-13db-1d73a897d301
    05/03/2018 13:26:22.87  PowerShell.exe (0x6D64)                  0x6C84 Search                         Usage Analytics                afxw1 Critical UsageAnalyticsTimerJob-890cf520-36e4-4d8a-8ec1-eaf4e2b49095 : Previous execution of the analysis failed (consecutive failed runs: 33024). 72025bae-97a8-0001-13db-1d73a897d301
    05/03/2018 13:26:22.87  PowerShell.exe (0x6D64)                  0x6C84 Search                         Usage Analytics                afnc0 Monitorable Analysis has failed for 33024 consecutive runs. Entering failure mode. 72025bae-97a8-0001-13db-1d73a897d301
    05/03/2018 13:26:22.87  PowerShell.exe (0x6D64)                  0x6C84 Search                         Usage Analytics                afncl Medium   Switching polling mode from Normal to Failure 72025bae-97a8-0001-13db-1d73a897d301
    05/03/2018 13:26:22.95  PowerShell.exe (0x6D64)                  0x6C84 Search                         Usage Analytics                afncm High     Analysis has not started in 230 days. 72025bae-97a8-0001-13db-1d73a897d301
    05/03/2018 13:26:22.98  PowerShell.exe (0x6D64)                  0x6C84 Search                         Usage Analytics                agwo7 Critical UsageAnalyticsTimerJob-890cf520-36e4-4d8a-8ec1-eaf4e2b49095 : Search Analytics has not completed for 240 days. Last completed at: 09/05/2017 00:36:46. 72025bae-97a8-0001-13db-1d73a897d301
    05/03/2018 13:26:22.98  PowerShell.exe (0x6D64)                  0x6C84 Search                         Usage Analytics                agwo8 Critical UsageAnalyticsTimerJob-890cf520-36e4-4d8a-8ec1-eaf4e2b49095 : Failed to start Usage Analysis. 72025bae-97a8-0001-13db-1d73a897d301
    05/03/2018 13:26:22.98  PowerShell.exe (0x6D64)                  0x6C84 Search                         Usage Analytics                agwo9 Monitorable Last successful SA analysis was run : 09/05/2017 00:36:46. This is more than 10 days, so we cannot run analysis 72025bae-97a8-0001-13db-1d73a897d301


    After that I looked the Usage/Logging database we configured for Usage Service applciation and validated if the count is getting updated.
    Select count (*) from RequestUsage (nolock)

    I checked the count, ran the MS Foundation Data Import job again and ran the query to confirm the count increased.

    Then, I ran the below job to check if there are any current entries, and I find a few with today's date.
    Select userlogin,* from dbo.RequestUsage (nolock) where RequestType=’GET’ order by RowCreatedTime desc

    I notice there are no current entries in the Search_AnalyticsReportingStore database,

    SELECT [ItemUri]
    ,[LastProcessingTime]
    ,[LastProcessingHitsCount]
    ,[TotalHitsCount]
    ,[LastProcessingUUsCount]
    ,[TotalUUsCount]

    FROM
    [Search_AnalyticsReportingStore].[dbo].[AnalyticsItemData]


    Could someone give me a lead on what else can I check to resolve this issue. I greatly appreciate the help!!

    jeudi 3 mai 2018 18:26

Toutes les réponses