Back from Holliday with a sequel for my last post. To quickly summarize our problem, we noticed very long wait times before jobs executed by the TFSJobAgent where executed. Things like triggering builds or releases, sending notifications and emails took hours before they got executed.
Will diving into the TFS administration pages, we identified the TFVC_RepositoryCodeIndexing jobs used for search as the root cause of the issue.
Let’s drill deeper into the problem by looking at a specific job log:
Events (46099) completed with status FailedAndRetry. Event 46099 completed with message 'Patch-PeriodicCatchUp: Code patch operation for Repository Id 96f8a036-54bc-47dc-9c37-08fc23d4a07b failed with error Error code -----> MaxAcceptableFractionOfFailedItemsInCrawlerThresholdBreached Exception message -----> Could not download content of lots of files, hence failing this Job. Failed Items Count: 38, Total Items: 38. Exception type -----> Microsoft.VisualStudio.Services.Search.Common.CrawlerException Exception source -----> Microsoft.VisualStudio.Services.Search.Crawler Stack trace, at Microsoft.VisualStudio.Services.Search.Crawler.Definitions.AbstractCrawler.ThrowIfFailedCrawlItemsBreachThreshold(Int32 failedRecordsCount, Int32 totalItemsToBeCrawled) at Microsoft.VisualStudio.Services.Search.Crawler.Extensions.Code.Tfvc.TfvcPatchHttpCrawler.TfvcCodeTraverser(TfvcPatchIndexCrawlSpec crawlSpec, TfvcHttpClientWrapper tfvcHttpWrapper, CrawlSinkParams crawlSinkParams) at Microsoft.VisualStudio.Services.Search.Crawler.Definitions.AbstractCrawler.Run(IndexingExecutionContext indexingExecutionContext) --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at Microsoft.VisualStudio.Services.Search.Crawler.Definitions.AbstractCrawler.Run(IndexingExecutionContext indexingExecutionContext) at Microsoft.VisualStudio.Services.Search.Server.Jobs.Operations.SingleStageCPF.ExecutePipeline(PipelineContext pipelineContext, StringBuilder resultMessage, BookkeepOperation bookkeepOp) at Microsoft.VisualStudio.Services.Search.Server.Jobs.Operations.SingleStageCPF.Run(PipelineContext pipelineContext, StringBuilder resultMessage) --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at Microsoft.VisualStudio.Services.Search.Server.Jobs.Operations.SingleStageCPF.Run(PipelineContext pipelineContext, StringBuilder resultMessage) at Microsoft.VisualStudio.Services.Search.Server.Jobs.Operations.Code.RepositoryCodeIndexingOperation.ExecuteCrawlerParserAndFeeder(PipelineContext pipelineContext, StringBuilder resultMessage) at Microsoft.VisualStudio.Services.Search.Server.Jobs.Operations.Code.RepositoryCodePatchOperation.RunOperation(IndexingExecutionContext indexingExecutionContext) [Crawler phase Total items crawled = 0. Time Taken = 15962320ms for Crawl spec type 'Microsoft.VisualStudio.Services.Search.Crawler.CrawlSpecs.TfvcPatchIndexCrawlSpec', Crawler extension 'Microsoft.VisualStudio.Services.Search.Crawler.Extensions.Code.Tfvc.TfvcPatchHttpCrawler'. ]'. OnPremiseTelemetryProperties :{"TFS.Search.Indexing.ParentCorrelationId":"5e7dfff9-485c-42ad-9101-8a258f530276","TFS.Search.Indexing.CorrelationId":"c911ee0a-2001-43fb-987d-96bb4bb8d826","TFS.Search.Indexing.CollectionName":"DefaultCollection","TFS.Search.Indexing.CollectionId":"ce06fba0-ec2f-466a-8569-1e9a13789614","TFS.Search.Indexing.ProjectName":"Ner","TFS.Search.Indexing.ProjectId":"96f8a036-54bc-47dc-9c37-08fc23d4a07b","TFS.Search.Indexing.ProjectIndexingUnitId":"144","TFS.Search.Indexing.RepositoryName":"$/Ner","TFS.Search.Indexing.RepositoryId":"96f8a036-54bc-47dc-9c37-08fc23d4a07b","TFS.Search.Indexing.RepositoryIndexingUnitId":"145","TFS.Search.Indexing.CrawlerServiceFailure":"1","TFS.Search.Indexing.CrawlerServiceFailureReason":"Microsoft.VisualStudio.Services.Search.Common.CrawlerException","TFS.Search.Indexing.CrawlingTime":"15962320","TFS.Search.Indexing.OperationStatus":"Failed","TFS.Search.Indexing.EntityType":"Code","TFS.Search.Indexing.IndexingUnitType":"TFVC_Repository","TFS.Search.Indexing.ChangeType":"Patch","TFS.Search.Indexing.JobExecutionTime":"15962332"} |
We were able to see the specific items that failed to index by executing the following query on the collection databases: select [IndexingUnitId] from [<collection_db>].[Search].[tbl_IndexingUnit] where TFSEntityId like ‘96f8a036-54bc-47dc-9c37-08fc23d4a07b’ select * from [<collection_db>].[Search].[tbl_ItemLevelFailures] where IndexingUnitId = <IndexingUnitId fetched above> Unfortunately this didn’t bring us any closer to a solution. In the end we choose the most drastic approach, removed the Search extensions from all collections and removed ElasticSearch itself(https://bartwullems.blogspot.com/2017/11/tfs-2018-remove-elasticsearch.html). After everything was removed, we reinstalled ElasticSearch, added the Search extensions again and this time everything seemed to work… |