Skip to content

VSB-TUO/Restore changes from commit solr logs #1112

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
milanmajchrak merged 1 commit into from
Oct 9, 2025
Merged

VSB-TUO/Restore changes from commit solr logs #1112

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
90 changes: 1 addition & 89 deletions dspace-api/src/main/java/org/dspace/discovery/SolrServiceImpl.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -779,26 +779,12 @@ public Iterator<Item> iteratorSearch(Context context, IndexableObject dso, Disco
@Override
public DiscoverResult search(Context context, DiscoverQuery discoveryQuery)
throws SearchServiceException {
long startTime = System.currentTimeMillis();
log.info("SolrServiceImpl.search - Starting search with query: '{}'", discoveryQuery.getQuery());

try {
if (solrSearchCore.getSolr() == null) {
log.warn("SolrServiceImpl.search - Solr core is null, returning empty result");
return new DiscoverResult();
}

DiscoverResult result = retrieveResult(context, discoveryQuery);

long totalTime = System.currentTimeMillis() - startTime;
log.info("SolrServiceImpl.search - Search completed in {} ms, found {} total results",
totalTime, result.getTotalSearchResults());

return result;

return retrieveResult(context, discoveryQuery);
} catch (Exception e) {
long totalTime = System.currentTimeMillis() - startTime;
log.error("SolrServiceImpl.search - Search failed after {} ms: {}", totalTime, e.getMessage(), e);
throw new org.dspace.discovery.SearchServiceException(e.getMessage(), e);
}
}
Expand Down Expand Up @@ -871,10 +857,6 @@ public Item next() {

protected SolrQuery resolveToSolrQuery(Context context, DiscoverQuery discoveryQuery)
throws SearchServiceException {
long methodStart = System.currentTimeMillis();
log.debug("SolrServiceImpl.resolveToSolrQuery - Starting query resolution for: '{}'",
discoveryQuery.getQuery());

SolrQuery solrQuery = new SolrQuery();

String query = "*:*";
Expand Down Expand Up @@ -1008,75 +990,39 @@ protected SolrQuery resolveToSolrQuery(Context context, DiscoverQuery discoveryQ
for (SolrServiceSearchPlugin searchPlugin : solrServiceSearchPlugins) {
searchPlugin.additionalSearchParameters(context, discoveryQuery, solrQuery);
}

long methodTime = System.currentTimeMillis() - methodStart;
log.debug("SolrServiceImpl.resolveToSolrQuery - Query resolution completed in {} ms, final query: '{}'",
methodTime, solrQuery.getQuery());

return solrQuery;
}

protected DiscoverResult retrieveResult(Context context, DiscoverQuery query)
throws SQLException, SolrServerException, IOException, SearchServiceException {
long methodStartTime = System.currentTimeMillis();
log.info("SolrServiceImpl.retrieveResult - Starting result retrieval for query: '{}'", query.getQuery());

// we use valid and executeLimit to decide if the solr query need to be re-run if we found some stale objects
boolean valid = false;
int executionCount = 0;
DiscoverResult result = null;

long solrQueryBuildStart = System.currentTimeMillis();
SolrQuery solrQuery = resolveToSolrQuery(context, query);
long solrQueryBuildTime = System.currentTimeMillis() - solrQueryBuildStart;
log.debug("SolrServiceImpl.retrieveResult - SolrQuery build took {} ms", solrQueryBuildTime);

// how many re-run of the query are allowed other than the first run
int maxAttempts = configurationService.getIntProperty("discovery.removestale.attempts", 3);

do {
long attemptStart = System.currentTimeMillis();
executionCount++;
log.debug("SolrServiceImpl.retrieveResult - Starting attempt {} of {}", executionCount, maxAttempts + 1);

result = new DiscoverResult();
// if we found stale objects we can decide to skip execution of the remaining code to improve performance
boolean skipLoadingResponse = false;
// use zombieDocs to collect stale found objects
List<String> zombieDocs = new ArrayList<>();

long solrExecutionStart = System.currentTimeMillis();
QueryResponse solrQueryResponse = solrSearchCore.getSolr().query(solrQuery,
solrSearchCore.REQUEST_METHOD);
long solrExecutionTime = System.currentTimeMillis() - solrExecutionStart;
log.info("SolrServiceImpl.retrieveResult - Solr query execution took {} ms (attempt {}), QTime: {} ms",
solrExecutionTime, executionCount,
solrQueryResponse != null ? solrQueryResponse.getQTime() : "null");

if (solrQueryResponse != null) {
long resultProcessingStart = System.currentTimeMillis();

result.setSearchTime(solrQueryResponse.getQTime());
result.setStart(query.getStart());
result.setMaxResults(query.getMaxResults());
result.setTotalSearchResults(solrQueryResponse.getResults().getNumFound());
log.debug("SolrServiceImpl.retrieveResult - Processing {} documents from Solr response",
solrQueryResponse.getResults().size());

List<String> searchFields = query.getSearchFields();
int processedDocs = 0;
int staleDocsFound = 0;

for (SolrDocument doc : solrQueryResponse.getResults()) {
long docProcessingStart = System.currentTimeMillis();
processedDocs++;

IndexableObject indexableObject = findIndexableObject(context, doc);

if (indexableObject != null) {
result.addIndexableObject(indexableObject);
} else {
staleDocsFound++;
// log has warn because we try to fix the issue
log.warn(LogHelper.getHeader(context,
"Stale entry found in Discovery index,"
Expand Down Expand Up @@ -1123,43 +1069,23 @@ protected DiscoverResult retrieveResult(Context context, DiscoverQuery query)
}
}
}

long resultProcessingTime = System.currentTimeMillis() - resultProcessingStart;
log.debug("SolrServiceImpl.retrieveResult - Document processing took {} ms, processed {} docs, "
+ "found {} stale docs", resultProcessingTime, processedDocs, staleDocsFound);

//Resolve our facet field values
long facetFieldsStart = System.currentTimeMillis();
resolveFacetFields(context, query, result, skipLoadingResponse, solrQueryResponse);
long facetFieldsTime = System.currentTimeMillis() - facetFieldsStart;
log.debug("SolrServiceImpl.retrieveResult - Facet fields resolution took {} ms", facetFieldsTime);

//Resolve our json facet field values used for metadata browsing
long jsonFacetStart = System.currentTimeMillis();
resolveJsonFacetFields(context, result, solrQueryResponse);
long jsonFacetTime = System.currentTimeMillis() - jsonFacetStart;
log.debug("SolrServiceImpl.retrieveResult - JSON facet resolution took {} ms", jsonFacetTime);
}
// If any stale entries are found in the current page of results,
// we remove those stale entries and rerun the same query again.
// Otherwise, the query is valid and the results are returned.
if (!zombieDocs.isEmpty()) {
long staleCleanupStart = System.currentTimeMillis();
log.info("Cleaning " + zombieDocs.size() + " stale objects from Discovery Index");
log.info("ZombieDocs ");
zombieDocs.forEach(log::info);
solrSearchCore.getSolr().deleteById(zombieDocs);
solrSearchCore.getSolr().commit();
long staleCleanupTime = System.currentTimeMillis() - staleCleanupStart;
log.info("SolrServiceImpl.retrieveResult - Stale cleanup took {} ms for {} docs",
staleCleanupTime, zombieDocs.size());
} else {
valid = true;
}

long attemptTime = System.currentTimeMillis() - attemptStart;
log.debug("SolrServiceImpl.retrieveResult - Attempt {} completed in {} ms", executionCount, attemptTime);

} while (!valid && executionCount <= maxAttempts);

if (!valid && executionCount == maxAttempts) {
Expand All @@ -1169,11 +1095,6 @@ protected DiscoverResult retrieveResult(Context context, DiscoverQuery query)
log.fatal(message);
throw new RuntimeException(message);
}

long methodTotalTime = System.currentTimeMillis() - methodStartTime;
log.info("SolrServiceImpl.retrieveResult - Total method execution took {} ms over {} attempts",
methodTotalTime, executionCount);

return result;
}

Expand Down Expand Up @@ -1308,24 +1229,15 @@ private void resolveFacetFields(Context context, DiscoverQuery query, DiscoverRe
* An exception that provides information on a database access error or other errors.
*/
protected IndexableObject findIndexableObject(Context context, SolrDocument doc) throws SQLException {
long startTime = System.currentTimeMillis();
String type = (String) doc.getFirstValue(SearchUtils.RESOURCE_TYPE_FIELD);
String id = (String) doc.getFirstValue(SearchUtils.RESOURCE_ID_FIELD);

final IndexFactory indexableObjectService = indexObjectServiceFactory.
getIndexFactoryByType(type);
Optional<IndexableObject> indexableObject = indexableObjectService.findIndexableObject(context, id);

if (!indexableObject.isPresent()) {
log.warn("Not able to retrieve object RESOURCE_ID:" + id + " - RESOURCE_TYPE_ID:" + type);
}

long findTime = System.currentTimeMillis() - startTime;
if (findTime > 10) { // Only log if it takes more than 10ms
log.debug("SolrServiceImpl.findIndexableObject - Finding object took {} ms for type: {}, id: {}",
findTime, type, id);
}

return indexableObject.orElse(null);
}

Expand Down
28 changes: 0 additions & 28 deletions ...e-server-webapp/src/main/java/org/dspace/app/rest/repository/DiscoveryRestRepository.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -134,47 +134,19 @@ public FacetResultsRest getFacetObjects(String facetName, String prefix, String
String dsoScope, final String configuration, List<SearchFilter> searchFilters, Pageable page)
throws SearchServiceException {

long startTime = System.currentTimeMillis();
log.info("getFacetObjects - Start processing facet '{}' with query '{}' and {} search filters",
facetName, query, searchFilters != null ? searchFilters.size() : 0);

Context context = obtainContext();

long scopeResolveStart = System.currentTimeMillis();
IndexableObject scopeObject = scopeResolver.resolveScope(context, dsoScope);
long scopeResolveTime = System.currentTimeMillis() - scopeResolveStart;
log.debug("getFacetObjects - Scope resolution took {} ms", scopeResolveTime);

long configStart = System.currentTimeMillis();
DiscoveryConfiguration discoveryConfiguration = searchConfigurationService
.getDiscoveryConfigurationByNameOrIndexableObject(context, configuration, scopeObject);
long configTime = System.currentTimeMillis() - configStart;
log.debug("getFacetObjects - Configuration loading took {} ms", configTime);

long queryBuildStart = System.currentTimeMillis();
DiscoverQuery discoverQuery = queryBuilder.buildFacetQuery(context, scopeObject, discoveryConfiguration, prefix,
query, searchFilters, dsoTypes, page, facetName);
long queryBuildTime = System.currentTimeMillis() - queryBuildStart;
log.debug("getFacetObjects - Query building took {} ms", queryBuildTime);

long searchStart = System.currentTimeMillis();
log.info("getFacetObjects - Starting Solr search for facet '{}' with built query", facetName);
DiscoverResult searchResult = searchService.search(context, scopeObject, discoverQuery);
long searchTime = System.currentTimeMillis() - searchStart;
log.info("getFacetObjects - Solr search completed in {} ms for facet '{}', found {} results",
searchTime, facetName, searchResult.getTotalSearchResults());

long conversionStart = System.currentTimeMillis();
FacetResultsRest facetResultsRest = discoverFacetResultsConverter.convert(context, facetName, prefix, query,
dsoTypes, dsoScope, searchFilters, searchResult, discoveryConfiguration, page,
utils.obtainProjection());
long conversionTime = System.currentTimeMillis() - conversionStart;
log.debug("getFacetObjects - Result conversion took {} ms", conversionTime);

long totalTime = System.currentTimeMillis() - startTime;
log.info("getFacetObjects - Total processing time: {} ms " +
"(scope: {}ms, config: {}ms, query: {}ms, search: {}ms, conversion: {}ms)",
totalTime, scopeResolveTime, configTime, queryBuildTime, searchTime, conversionTime);

return facetResultsRest;
}
Expand Down