Add logging for slow operations in profile data services (#309)

sarkikos · web-flow · commit 4a94aaabcb42 · 2026-04-28T15:24:08.000+03:00
diff --git a/aspnetcore/src/api/Models/Common/Constants.cs b/aspnetcore/src/api/Models/Common/Constants.cs
@@ -198,5 +198,10 @@ public static class FactContributionTypes
             public const string ACTIVITY_TYPE = "activity_type";
             public const string RESEARCHER_NAME_ACTIVITY = "researcher_name_activity";
         }
+
+        public static class LoggingParameters
+        {
+            public const int SLOW_OPERATION_MS_THRESHOLD = 2000;
+        }
     }
 }
diff --git a/aspnetcore/src/api/Services/Profiledata/AffiliationService.cs b/aspnetcore/src/api/Services/Profiledata/AffiliationService.cs
@@ -353,7 +353,11 @@ public async Task<List<ProfileEditorAffiliation>> GetProfileEditorAffiliations(i
             }
 
             stopwatch.Stop();
-            _logger.LogInformation($"GetProfileEditorAffiliations. {affiliations.Count} items in {stopwatch.ElapsedMilliseconds}ms.");
+            if (stopwatch.ElapsedMilliseconds > Constants.LoggingParameters.SLOW_OPERATION_MS_THRESHOLD)
+            {
+                _logger.LogWarning($"GetProfileEditorAffiliations is slow. userprofileId={userprofileId}, forElasticsearch={forElasticsearch}, {affiliations.Count} items in {stopwatch.ElapsedMilliseconds}ms.");
+            }
+            
             return affiliations;
         }
     }
diff --git a/aspnetcore/src/api/Services/Profiledata/EducationService.cs b/aspnetcore/src/api/Services/Profiledata/EducationService.cs
@@ -99,7 +99,10 @@ public async Task<List<ProfileEditorEducation>> GetProfileEditorEducations(int u
             }
 
             stopwatch.Stop();
-            _logger.LogInformation($"GetProfileEditorEducations. {educations.Count} items in {stopwatch.ElapsedMilliseconds}ms.");
+            if (stopwatch.ElapsedMilliseconds > Constants.LoggingParameters.SLOW_OPERATION_MS_THRESHOLD)
+            {
+                _logger.LogWarning($"GetProfileEditorEducations is slow. userprofileId={userprofileId}, forElasticsearch={forElasticsearch}, {educations.Count} items in {stopwatch.ElapsedMilliseconds}ms.");
+            }
 
             return educations;
         }  
diff --git a/aspnetcore/src/api/Services/Profiledata/EmailService.cs b/aspnetcore/src/api/Services/Profiledata/EmailService.cs
@@ -77,7 +77,10 @@ public async Task<List<ProfileEditorEmail>> GetProfileEditorEmails(int userprofi
             }
 
             stopwatch.Stop();
-            _logger.LogInformation($"GetProfileEditorEmails. {emails.Count} items in {stopwatch.ElapsedMilliseconds}ms.");
+            if (stopwatch.ElapsedMilliseconds > Constants.LoggingParameters.SLOW_OPERATION_MS_THRESHOLD)
+            {
+                _logger.LogWarning($"GetProfileEditorEmails is slow. userprofileId={userprofileId}, forElasticsearch={forElasticsearch}, {emails.Count} items in {stopwatch.ElapsedMilliseconds}ms.");
+            }
 
             return emails;
         }
diff --git a/aspnetcore/src/api/Services/Profiledata/ExternalIdentifierService.cs b/aspnetcore/src/api/Services/Profiledata/ExternalIdentifierService.cs
@@ -78,7 +78,10 @@ public async Task<List<ProfileEditorExternalIdentifier>> GetProfileEditorExterna
             }
 
             stopwatch.Stop();
-            _logger.LogInformation($"GetProfileEditorExternalIdentifiers. {externalIdentifiers.Count} items in {stopwatch.ElapsedMilliseconds}ms.");
+            if (stopwatch.ElapsedMilliseconds > Constants.LoggingParameters.SLOW_OPERATION_MS_THRESHOLD)
+            {
+                _logger.LogWarning($"GetProfileEditorExternalIdentifiers is slow. userprofileId={userprofileId}, forElasticsearch={forElasticsearch}, {externalIdentifiers.Count} items in {stopwatch.ElapsedMilliseconds}ms.");
+            }
 
             return externalIdentifiers;
         }
diff --git a/aspnetcore/src/api/Services/Profiledata/FundingDecisionService.cs b/aspnetcore/src/api/Services/Profiledata/FundingDecisionService.cs
@@ -357,7 +357,10 @@ public async Task<List<ProfileEditorFundingDecision>> GetProfileEditorFundingDec
             }
 
             stopwatch.Stop();
-            _logger.LogInformation($"GetProfileEditorFundingDecisions. {fundingDecisions.Count} items in {stopwatch.ElapsedMilliseconds}ms.");
+            if (stopwatch.ElapsedMilliseconds > Constants.LoggingParameters.SLOW_OPERATION_MS_THRESHOLD)
+            {
+                _logger.LogWarning($"GetProfileEditorFundingDecisions is slow. userprofileId={userprofileId}, forElasticsearch={forElasticsearch}, {fundingDecisions.Count} items in {stopwatch.ElapsedMilliseconds}ms.");
+            }
 
             return fundingDecisions;
         }
diff --git a/aspnetcore/src/api/Services/Profiledata/KeywordService.cs b/aspnetcore/src/api/Services/Profiledata/KeywordService.cs
@@ -81,7 +81,10 @@ public async Task<List<ProfileEditorKeyword>> GetProfileEditorKeywords(int userp
             }
 
             stopwatch.Stop();
-            _logger.LogInformation($"GetProfileEditorKeywords. {keywords.Count} items in {stopwatch.ElapsedMilliseconds}ms.");
+            if (stopwatch.ElapsedMilliseconds > Constants.LoggingParameters.SLOW_OPERATION_MS_THRESHOLD)
+            {
+                _logger.LogWarning($"GetProfileEditorKeywords is slow. userprofileId={userprofileId}, forElasticsearch={forElasticsearch}, {keywords.Count} items in {stopwatch.ElapsedMilliseconds}ms.");
+            }
 
             return keywords;
         }
diff --git a/aspnetcore/src/api/Services/Profiledata/NameService.cs b/aspnetcore/src/api/Services/Profiledata/NameService.cs
@@ -136,7 +136,10 @@ public async Task<List<ProfileEditorName>> GetProfileEditorOtherNames(int userpr
             }
 
             stopwatch.Stop();
-            _logger.LogInformation($"GetProfileEditorOtherNames. {otherNames.Count} items in {stopwatch.ElapsedMilliseconds}ms.");
+            if (stopwatch.ElapsedMilliseconds > Constants.LoggingParameters.SLOW_OPERATION_MS_THRESHOLD)
+            {
+                _logger.LogWarning($"GetProfileEditorOtherNames is slow. userprofileId={userprofileId}, forElasticsearch={forElasticsearch}, {otherNames.Count} items in {stopwatch.ElapsedMilliseconds}ms.");
+            }
 
             return otherNames;
         }
diff --git a/aspnetcore/src/api/Services/Profiledata/PublicationService.cs b/aspnetcore/src/api/Services/Profiledata/PublicationService.cs
@@ -336,7 +336,10 @@ void ProcessItem(PublicationDto newPublication)
             }
 
             stopwatch.Stop();
-            _logger.LogInformation($"GetProfileEditorPublications. {publications.Count} items in {stopwatch.ElapsedMilliseconds}ms.");
+            if (stopwatch.ElapsedMilliseconds > Constants.LoggingParameters.SLOW_OPERATION_MS_THRESHOLD)
+            {
+                _logger.LogWarning($"GetProfileEditorPublications is slow. userprofileId={userprofileId}, forElasticsearch={forElasticsearch}, {publications.Count} items in {stopwatch.ElapsedMilliseconds}ms.");
+            }
 
             return publications;
         }
diff --git a/aspnetcore/src/api/Services/Profiledata/ResearchActivityService.cs b/aspnetcore/src/api/Services/Profiledata/ResearchActivityService.cs
@@ -114,7 +114,6 @@ public async Task<List<ProfileEditorActivityAndReward>> GetProfileEditorActivies
             /*
              * DimResearchActivity => DTO
              */
-            var stopwatch_researchActivityDtos = Stopwatch.StartNew();
             List<ResearchActivityDto> researchActivityDtos = await _ttvContext.FactFieldValues.Where(ffv => ffv.DimUserProfileId == userprofileId
                 && ffv.DimResearchActivityId > 0
                 && ffv.DimFieldDisplaySettings.FieldIdentifier == Constants.FieldIdentifiers.ACTIVITY_RESEARCH_ACTIVITY
@@ -216,13 +215,10 @@ public async Task<List<ProfileEditorActivityAndReward>> GetProfileEditorActivies
                         LinkType = wl.LinkType ?? ""
                     }).ToList() 
                 }).AsNoTracking().ToListAsync();
-            stopwatch_researchActivityDtos.Stop();
-            _logger.LogInformation($"GetProfileEditorResearchActivities. SQL query for researchActivityDtos got {researchActivityDtos.Count} items and took {stopwatch_researchActivityDtos.ElapsedMilliseconds}ms.");
 
             /*
              * DimProfileOnlyResearchActivity => DTO
              */
-            var stopwatch_profileOnlyResearchActivityDtos = Stopwatch.StartNew();
             List<ResearchActivityDto> profileOnlyResearchActivityDtos = await _ttvContext.FactFieldValues.Where(ffv => ffv.DimUserProfileId == userprofileId
                 && ffv.DimProfileOnlyResearchActivityId > 0
                 && ffv.DimFieldDisplaySettings.FieldIdentifier == Constants.FieldIdentifiers.ACTIVITY_RESEARCH_ACTIVITY
@@ -297,14 +293,11 @@ public async Task<List<ProfileEditorActivityAndReward>> GetProfileEditorActivies
                         LinkType = wl.LinkType ?? ""
                     }).ToList() 
                 }).AsNoTracking().ToListAsync();
-            stopwatch_profileOnlyResearchActivityDtos.Stop();
-            _logger.LogInformation($"GetProfileEditorResearchActivities. SQL query for profileOnlyResearchActivityDtos got {profileOnlyResearchActivityDtos.Count} items and took {stopwatch_profileOnlyResearchActivityDtos.ElapsedMilliseconds}ms.");
 
             /*
             * Batch load child identifierless data.
             * One query replaces 4 correlated subqueries per row across both DTO lists.
             */
-            var stopwatch_childLookup = Stopwatch.StartNew();
             List<int> allParentIds = researchActivityDtos
                 .Concat(profileOnlyResearchActivityDtos)
                 .Where(d => d.DimIdentifierlessData_Id > 0)
@@ -338,16 +331,13 @@ public async Task<List<ProfileEditorActivityAndReward>> GetProfileEditorActivies
                     }
                 }
             }
-            stopwatch_childLookup.Stop();
-            _logger.LogInformation($"GetProfileEditorResearchActivities. Batch child lookup took {stopwatch_childLookup.ElapsedMilliseconds}ms.");
 
             /*
              * Research activity deduplication.
              * Deduplication is based on start year and name properties.
              * Remove items from profileOnlyResearchActivityDtos which duplicate items from researchActivityDtos.
              * Comparison is done by computing a key for each research activity based on start year and translated name FI, and comparing the keys.
              */
-            var stopwatch_deduplicateDtos = Stopwatch.StartNew();
             HashSet<string> uniqueKeys = new();
             foreach (ResearchActivityDto researchActivityDto in researchActivityDtos)
             {
@@ -392,7 +382,6 @@ public async Task<List<ProfileEditorActivityAndReward>> GetProfileEditorActivies
                     uniqueKeys.Add(key);
                 }
             }
-            _logger.LogInformation($"GetProfileEditorResearchActivities. Deduplication took {stopwatch_deduplicateDtos.ElapsedMilliseconds}ms.");
 
             /*
              * Process DTOs
@@ -402,7 +391,6 @@ public async Task<List<ProfileEditorActivityAndReward>> GetProfileEditorActivies
              * Destination:
              *   - List<ProfileEditorActivityAndReward>
              */
-            var stopwatch_processDtos = Stopwatch.StartNew();
             List<ProfileEditorActivityAndReward> activitiesAndRewards = new();
             foreach (ResearchActivityDto dto in researchActivityDtos.Concat(profileOnlyResearchActivityDtos).Where(d => !d.IsDuplicate))
             {
@@ -617,11 +605,12 @@ public async Task<List<ProfileEditorActivityAndReward>> GetProfileEditorActivies
                 }
                 activitiesAndRewards.Add(activityAndReward);
             }
-            stopwatch_processDtos.Stop();
-            _logger.LogInformation($"GetProfileEditorResearchActivities. Processing DTOs took {stopwatch_processDtos.ElapsedMilliseconds}ms.");
 
             stopwatch.Stop();
-            _logger.LogInformation($"GetProfileEditorResearchActivities. {activitiesAndRewards.Count} items in {stopwatch.ElapsedMilliseconds}ms.");
+            if (stopwatch.ElapsedMilliseconds > Constants.LoggingParameters.SLOW_OPERATION_MS_THRESHOLD)
+            {
+                _logger.LogWarning($"GetProfileEditorResearchActivities is slow. userprofileId={userprofileId}, forElasticsearch={forElasticsearch}, {activitiesAndRewards.Count} items in {stopwatch.ElapsedMilliseconds}ms.");
+            }
 
             return activitiesAndRewards;
         }
diff --git a/aspnetcore/src/api/Services/Profiledata/ResearchDatasetService.cs b/aspnetcore/src/api/Services/Profiledata/ResearchDatasetService.cs
@@ -263,7 +263,10 @@ public async Task<List<ProfileEditorResearchDataset>> GetProfileEditorResearchDa
             }
 
             stopwatch.Stop();
-            _logger.LogInformation($"GetProfileEditorResearchDatasets. {researchDatasets.Count} items in {stopwatch.ElapsedMilliseconds}ms.");
+            if (stopwatch.ElapsedMilliseconds > Constants.LoggingParameters.SLOW_OPERATION_MS_THRESHOLD)
+            {
+                _logger.LogWarning($"GetProfileEditorResearchDatasets is slow. userprofileId={userprofileId}, forElasticsearch={forElasticsearch}, {researchDatasets.Count} items in {stopwatch.ElapsedMilliseconds}ms.");
+            }
 
             return researchDatasets;
         }
diff --git a/aspnetcore/src/api/Services/Profiledata/ResearcherDescriptionService.cs b/aspnetcore/src/api/Services/Profiledata/ResearcherDescriptionService.cs
@@ -100,7 +100,10 @@ public async Task<List<ProfileEditorResearcherDescription>> GetProfileEditorRese
             }
 
             stopwatch.Stop();
-            _logger.LogInformation($"GetProfileEditorResearcherDescriptions. {researcherDescriptions.Count} items in {stopwatch.ElapsedMilliseconds}ms.");
+            if (stopwatch.ElapsedMilliseconds > Constants.LoggingParameters.SLOW_OPERATION_MS_THRESHOLD)
+            {
+                _logger.LogWarning($"GetProfileEditorResearcherDescriptions is slow. userprofileId={userprofileId}, forElasticsearch={forElasticsearch}, {researcherDescriptions.Count} items in {stopwatch.ElapsedMilliseconds}ms.");
+            }
             
             return researcherDescriptions;
         }
diff --git a/aspnetcore/src/api/Services/Profiledata/TelephoneNumberService.cs b/aspnetcore/src/api/Services/Profiledata/TelephoneNumberService.cs
@@ -77,7 +77,10 @@ public async Task<List<ProfileEditorTelephoneNumber>> GetProfileEditorTelephoneN
             }
 
             stopwatch.Stop();
-            _logger.LogInformation($"GetProfileEditorTelephoneNumbers. {telephoneNumbers.Count} items in {stopwatch.ElapsedMilliseconds}ms.");
+            if (stopwatch.ElapsedMilliseconds > Constants.LoggingParameters.SLOW_OPERATION_MS_THRESHOLD)
+            {
+                _logger.LogWarning($"GetProfileEditorTelephoneNumbers is slow. userprofileId={userprofileId}, forElasticsearch={forElasticsearch}, {telephoneNumbers.Count} items in {stopwatch.ElapsedMilliseconds}ms.");
+            }
 
             return telephoneNumbers;
         }
diff --git a/aspnetcore/src/api/Services/Profiledata/UniqueDataSourcesService.cs b/aspnetcore/src/api/Services/Profiledata/UniqueDataSourcesService.cs
@@ -63,7 +63,10 @@ public async Task<List<ProfileEditorSource>> GetUniqueDataSources(int userprofil
             }
 
             stopwatch.Stop();
-            _logger.LogInformation($"GetUniqueDataSources. {dataSources.Count} items in {stopwatch.ElapsedMilliseconds}ms.");
+            if (stopwatch.ElapsedMilliseconds > Constants.LoggingParameters.SLOW_OPERATION_MS_THRESHOLD)
+            {
+                _logger.LogWarning($"GetUniqueDataSources is slow. userprofileId={userprofileId}, forElasticsearch={forElasticsearch}, {dataSources.Count} items in {stopwatch.ElapsedMilliseconds}ms.");
+            }
 
             return dataSources;
         }
diff --git a/aspnetcore/src/api/Services/Profiledata/WebLinkService.cs b/aspnetcore/src/api/Services/Profiledata/WebLinkService.cs
@@ -79,7 +79,10 @@ public async Task<List<ProfileEditorWebLink>> GetProfileEditorWebLinks(int userp
             }
 
             stopwatch.Stop();
-            _logger.LogInformation($"GetProfileEditorWebLinks. {webLinks.Count} items in {stopwatch.ElapsedMilliseconds}ms.");
+            if (stopwatch.ElapsedMilliseconds > Constants.LoggingParameters.SLOW_OPERATION_MS_THRESHOLD)
+            {
+                _logger.LogWarning($"GetProfileEditorWebLinks is slow. userprofileId={userprofileId}, forElasticsearch={forElasticsearch}, {webLinks.Count} items in {stopwatch.ElapsedMilliseconds}ms.");
+            }
 
             return webLinks;
         }

Original file line number	Diff line number	Diff line change
`@@ -198,5 +198,10 @@ public static class FactContributionTypes`
`198`	`198`	`public const string ACTIVITY_TYPE = "activity_type";`
`199`	`199`	`public const string RESEARCHER_NAME_ACTIVITY = "researcher_name_activity";`
`200`	`200`	`}`
	`201`	`+`
	`202`	`+ public static class LoggingParameters`
	`203`	`+ {`
	`204`	`+ public const int SLOW_OPERATION_MS_THRESHOLD = 2000;`
	`205`	`+ }`
`201`	`206`	`}`
`202`	`207`	`}`
Original file line number	Diff line number	Diff line change
`@@ -353,7 +353,11 @@ public async Task<List<ProfileEditorAffiliation>> GetProfileEditorAffiliations(i`
`353`	`353`	`}`
`354`	`354`
`355`	`355`	`stopwatch.Stop();`
`356`		`- _logger.LogInformation($"GetProfileEditorAffiliations. {affiliations.Count} items in {stopwatch.ElapsedMilliseconds}ms.");`
	`356`	`+ if (stopwatch.ElapsedMilliseconds > Constants.LoggingParameters.SLOW_OPERATION_MS_THRESHOLD)`
	`357`	`+ {`
	`358`	`+ _logger.LogWarning($"GetProfileEditorAffiliations is slow. userprofileId={userprofileId}, forElasticsearch={forElasticsearch}, {affiliations.Count} items in {stopwatch.ElapsedMilliseconds}ms.");`
	`359`	`+ }`
	`360`	`+`
`357`	`361`	`return affiliations;`
`358`	`362`	`}`
`359`	`363`	`}`
Original file line number	Diff line number	Diff line change
`@@ -99,7 +99,10 @@ public async Task<List<ProfileEditorEducation>> GetProfileEditorEducations(int u`
`99`	`99`	`}`
`100`	`100`
`101`	`101`	`stopwatch.Stop();`
`102`		`- _logger.LogInformation($"GetProfileEditorEducations. {educations.Count} items in {stopwatch.ElapsedMilliseconds}ms.");`
	`102`	`+ if (stopwatch.ElapsedMilliseconds > Constants.LoggingParameters.SLOW_OPERATION_MS_THRESHOLD)`
	`103`	`+ {`
	`104`	`+ _logger.LogWarning($"GetProfileEditorEducations is slow. userprofileId={userprofileId}, forElasticsearch={forElasticsearch}, {educations.Count} items in {stopwatch.ElapsedMilliseconds}ms.");`
	`105`	`+ }`
`103`	`106`
`104`	`107`	`return educations;`
`105`	`108`	`}`
Original file line number	Diff line number	Diff line change
`@@ -77,7 +77,10 @@ public async Task<List<ProfileEditorEmail>> GetProfileEditorEmails(int userprofi`
`77`	`77`	`}`
`78`	`78`
`79`	`79`	`stopwatch.Stop();`
`80`		`- _logger.LogInformation($"GetProfileEditorEmails. {emails.Count} items in {stopwatch.ElapsedMilliseconds}ms.");`
	`80`	`+ if (stopwatch.ElapsedMilliseconds > Constants.LoggingParameters.SLOW_OPERATION_MS_THRESHOLD)`
	`81`	`+ {`
	`82`	`+ _logger.LogWarning($"GetProfileEditorEmails is slow. userprofileId={userprofileId}, forElasticsearch={forElasticsearch}, {emails.Count} items in {stopwatch.ElapsedMilliseconds}ms.");`
	`83`	`+ }`
`81`	`84`
`82`	`85`	`return emails;`
`83`	`86`	`}`
Original file line number	Diff line number	Diff line change
`@@ -78,7 +78,10 @@ public async Task<List<ProfileEditorExternalIdentifier>> GetProfileEditorExterna`
`78`	`78`	`}`
`79`	`79`
`80`	`80`	`stopwatch.Stop();`
`81`		`- _logger.LogInformation($"GetProfileEditorExternalIdentifiers. {externalIdentifiers.Count} items in {stopwatch.ElapsedMilliseconds}ms.");`
	`81`	`+ if (stopwatch.ElapsedMilliseconds > Constants.LoggingParameters.SLOW_OPERATION_MS_THRESHOLD)`
	`82`	`+ {`
	`83`	`+ _logger.LogWarning($"GetProfileEditorExternalIdentifiers is slow. userprofileId={userprofileId}, forElasticsearch={forElasticsearch}, {externalIdentifiers.Count} items in {stopwatch.ElapsedMilliseconds}ms.");`
	`84`	`+ }`
`82`	`85`
`83`	`86`	`return externalIdentifiers;`
`84`	`87`	`}`
Original file line number	Diff line number	Diff line change
`@@ -357,7 +357,10 @@ public async Task<List<ProfileEditorFundingDecision>> GetProfileEditorFundingDec`
`357`	`357`	`}`
`358`	`358`
`359`	`359`	`stopwatch.Stop();`
`360`		`- _logger.LogInformation($"GetProfileEditorFundingDecisions. {fundingDecisions.Count} items in {stopwatch.ElapsedMilliseconds}ms.");`
	`360`	`+ if (stopwatch.ElapsedMilliseconds > Constants.LoggingParameters.SLOW_OPERATION_MS_THRESHOLD)`
	`361`	`+ {`
	`362`	`+ _logger.LogWarning($"GetProfileEditorFundingDecisions is slow. userprofileId={userprofileId}, forElasticsearch={forElasticsearch}, {fundingDecisions.Count} items in {stopwatch.ElapsedMilliseconds}ms.");`
	`363`	`+ }`
`361`	`364`
`362`	`365`	`return fundingDecisions;`
`363`	`366`	`}`
Original file line number	Diff line number	Diff line change
`@@ -81,7 +81,10 @@ public async Task<List<ProfileEditorKeyword>> GetProfileEditorKeywords(int userp`
`81`	`81`	`}`
`82`	`82`
`83`	`83`	`stopwatch.Stop();`
`84`		`- _logger.LogInformation($"GetProfileEditorKeywords. {keywords.Count} items in {stopwatch.ElapsedMilliseconds}ms.");`
	`84`	`+ if (stopwatch.ElapsedMilliseconds > Constants.LoggingParameters.SLOW_OPERATION_MS_THRESHOLD)`
	`85`	`+ {`
	`86`	`+ _logger.LogWarning($"GetProfileEditorKeywords is slow. userprofileId={userprofileId}, forElasticsearch={forElasticsearch}, {keywords.Count} items in {stopwatch.ElapsedMilliseconds}ms.");`
	`87`	`+ }`
`85`	`88`
`86`	`89`	`return keywords;`
`87`	`90`	`}`
Original file line number	Diff line number	Diff line change
`@@ -136,7 +136,10 @@ public async Task<List<ProfileEditorName>> GetProfileEditorOtherNames(int userpr`
`136`	`136`	`}`
`137`	`137`
`138`	`138`	`stopwatch.Stop();`
`139`		`- _logger.LogInformation($"GetProfileEditorOtherNames. {otherNames.Count} items in {stopwatch.ElapsedMilliseconds}ms.");`
	`139`	`+ if (stopwatch.ElapsedMilliseconds > Constants.LoggingParameters.SLOW_OPERATION_MS_THRESHOLD)`
	`140`	`+ {`
	`141`	`+ _logger.LogWarning($"GetProfileEditorOtherNames is slow. userprofileId={userprofileId}, forElasticsearch={forElasticsearch}, {otherNames.Count} items in {stopwatch.ElapsedMilliseconds}ms.");`
	`142`	`+ }`
`140`	`143`
`141`	`144`	`return otherNames;`
`142`	`145`	`}`
Original file line number	Diff line number	Diff line change
`@@ -336,7 +336,10 @@ void ProcessItem(PublicationDto newPublication)`
`336`	`336`	`}`
`337`	`337`
`338`	`338`	`stopwatch.Stop();`
`339`		`- _logger.LogInformation($"GetProfileEditorPublications. {publications.Count} items in {stopwatch.ElapsedMilliseconds}ms.");`
	`339`	`+ if (stopwatch.ElapsedMilliseconds > Constants.LoggingParameters.SLOW_OPERATION_MS_THRESHOLD)`
	`340`	`+ {`
	`341`	`+ _logger.LogWarning($"GetProfileEditorPublications is slow. userprofileId={userprofileId}, forElasticsearch={forElasticsearch}, {publications.Count} items in {stopwatch.ElapsedMilliseconds}ms.");`
	`342`	`+ }`
`340`	`343`
`341`	`344`	`return publications;`
`342`	`345`	`}`