Merge branch 'fix/SEARCH-2202_TrackerLogging' into 'master'

SEARCH-2202 Ensure each class has its own logger.

See merge request search_discovery/insightengine!482
This commit is contained in:
Tom Page
2020-04-28 16:30:59 +01:00
5 changed files with 59 additions and 54 deletions
@@ -43,8 +43,7 @@ public abstract class AbstractTracker implements Tracker
static final long TIME_STEP_32_DAYS_IN_MS = 1000 * 60 * 60 * 24 * 32L;
static final long TIME_STEP_1_HR_IN_MS = 60 * 60 * 1000L;
static final String SHARD_METHOD_DBID = "DB_ID";
protected final Logger logger = LoggerFactory.getLogger(getClass());
private static final Logger LOGGER = LoggerFactory.getLogger(AbstractTracker.class);
protected Properties props;
protected SOLRAPIClient client;
@@ -170,7 +169,7 @@ public abstract class AbstractTracker implements Tracker
if(runLock.availablePermits() == 0)
{
logger.info("[{} / {} / {}] Tracker already registered.", coreName, trackerId, iterationId);
LOGGER.info("[{} / {} / {}] Tracker already registered.", coreName, trackerId, iterationId);
return;
}
@@ -191,7 +190,7 @@ public abstract class AbstractTracker implements Tracker
{
this.state = getTrackerState();
logger.debug("[{} / {} / {}] Global Tracker State set to: {}", coreName, trackerId, iterationId, this.state.toString());
LOGGER.debug("[{} / {} / {}] Global Tracker State set to: {}", coreName, trackerId, iterationId, this.state.toString());
this.state.setRunning(true);
}
else
@@ -209,28 +208,25 @@ public abstract class AbstractTracker implements Tracker
catch(IndexTrackingShutdownException t)
{
setRollback(true, t);
logger.info("[{} / {} / {}] Tracking cycle stopped. See the stacktrace below for further details.", coreName, trackerId, iterationId, t);
LOGGER.info("[{} / {} / {}] Tracking cycle stopped. See the stacktrace below for further details.", coreName, trackerId, iterationId, t);
}
catch(Throwable t)
{
setRollback(true, t);
if (t instanceof SocketTimeoutException || t instanceof ConnectException)
{
logger.warn("[{} / {} / {}] Tracking communication timed out. See the stacktrace below for further details.", coreName, trackerId, iterationId);
if (logger.isDebugEnabled())
{
logger.debug("[{} / {} / {}] Stack trace", coreName, trackerId, iterationId, t);
}
LOGGER.warn("[{} / {} / {}] Tracking communication timed out. See the stacktrace below for further details.", coreName, trackerId, iterationId);
LOGGER.debug("[{} / {} / {}] Stack trace", coreName, trackerId, iterationId, t);
}
else
{
logger.error("[{} / {} / {}] Tracking failure. See the stacktrace below for further details.", coreName, trackerId, iterationId, t);
LOGGER.error("[{} / {} / {}] Tracking failure. See the stacktrace below for further details.", coreName, trackerId, iterationId, t);
}
}
}
catch (InterruptedException e)
{
logger.error("[{} / {} / {}] Semaphore interruption. See the stacktrace below for further details.", coreName, trackerId, iterationId, e);
LOGGER.error("[{} / {} / {}] Semaphore interruption. See the stacktrace below for further details.", coreName, trackerId, iterationId, e);
}
finally
{
@@ -18,6 +18,10 @@
*/
package org.alfresco.solr.tracker;
import static java.util.stream.Collectors.joining;
import static org.alfresco.solr.utils.Utils.notNullOrEmpty;
import java.io.IOException;
import java.util.ArrayList;
import java.util.HashSet;
@@ -31,24 +35,17 @@ import org.alfresco.solr.InformationServer;
import org.alfresco.solr.client.NodeMetaData;
import org.alfresco.solr.client.SOLRAPIClient;
import org.alfresco.solr.client.Transaction;
import org.apache.commons.codec.EncoderException;
import org.json.JSONException;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import static java.util.stream.Collectors.joining;
import static org.alfresco.solr.utils.Utils.notNullOrEmpty;
/*
* This tracks Cascading Updates
* @author Joel Bernstein
*/
public class CascadeTracker extends AbstractTracker implements Tracker
{
protected final static Logger log = LoggerFactory.getLogger(CascadeTracker.class);
private static final Logger LOGGER = LoggerFactory.getLogger(CascadeTracker.class);
public CascadeTracker(Properties p, SOLRAPIClient client, String coreName,
InformationServer informationServer)
@@ -64,7 +61,7 @@ public class CascadeTracker extends AbstractTracker implements Tracker
}
@Override
protected void doTrack(String iterationId) throws AuthenticationException, IOException, JSONException, EncoderException
protected void doTrack(String iterationId) throws IOException, JSONException
{
// MetadataTracker must wait until ModelTracker has run
ModelTracker modelTracker = this.infoSrv.getAdminHandler().getTrackerRegistry().getModelTracker();
@@ -74,15 +71,15 @@ public class CascadeTracker extends AbstractTracker implements Tracker
}
}
public void maintenance() throws Exception {
public void maintenance()
{
}
public boolean hasMaintenance() {
return false;
}
private void trackRepository(String iterationId) throws IOException, AuthenticationException, JSONException, EncoderException
private void trackRepository(String iterationId) throws IOException, JSONException
{
checkShutdown();
processCascades(iterationId);
@@ -123,7 +120,8 @@ public class CascadeTracker extends AbstractTracker implements Tracker
}
}
public void invalidateState() {
public void invalidateState()
{
super.invalidateState();
infoSrv.setCleanCascadeTxnFloor(-1);
}
@@ -131,55 +129,58 @@ public class CascadeTracker extends AbstractTracker implements Tracker
private void processCascades(String iterationId) throws IOException
{
int num = 50;
List<Transaction> txBatch = null;
do {
try {
List<Transaction> txBatch;
do
{
try
{
getWriteLock().acquire();
txBatch = infoSrv.getCascades(num);
if(txBatch.size() == 0) {
if(txBatch.size() == 0)
{
//No transactions to process for cascades.
return;
}
ArrayList<Long> txIds = new ArrayList<Long>();
Set<Long> txIdSet = new HashSet<Long>();
for (Transaction tx : txBatch) {
ArrayList<Long> txIds = new ArrayList<>();
Set<Long> txIdSet = new HashSet<>();
for (Transaction tx : txBatch)
{
txIds.add(tx.getId());
txIdSet.add(tx.getId());
}
List<NodeMetaData> nodeMetaDatas = infoSrv.getCascadeNodes(txIds);
//System.out.println("########### Cascade node meta datas:"+nodeMetaDatas.size());
if(nodeMetaDatas.size() > 0) {
LinkedList<NodeMetaData> stack = new LinkedList<NodeMetaData>();
if(nodeMetaDatas.size() > 0)
{
LinkedList<NodeMetaData> stack = new LinkedList<>();
stack.addAll(nodeMetaDatas);
int batchSize = 10;
do {
List<NodeMetaData> batch = new ArrayList<NodeMetaData>();
while (batch.size() < batchSize && stack.size() > 0) {
do
{
List<NodeMetaData> batch = new ArrayList<>();
while (batch.size() < batchSize && stack.size() > 0)
{
batch.add(stack.removeFirst());
}
CascadeIndexWorkerRunnable worker = new CascadeIndexWorkerRunnable(this.threadHandler, batch, infoSrv);
if (logger.isTraceEnabled())
if (LOGGER.isTraceEnabled())
{
String nodes = notNullOrEmpty(batch).stream()
.map(NodeMetaData::getId)
.map(Object::toString)
.collect(joining(","));
logger.trace("[{} / {} / {} / {}] Worker has been created for nodes {}", coreName, trackerId, iterationId, worker.hashCode(), nodes);
LOGGER.trace("[{} / {} / {} / {}] Worker has been created for nodes {}", coreName, trackerId, iterationId, worker.hashCode(), nodes);
}
this.threadHandler.scheduleTask(worker);
}
while (stack.size() > 0);
} while (stack.size() > 0);
}
//Update the transaction records.
updateTransactionsAfterAsynchronous(txBatch);
//System.out.println("######################: Finished Cascade Run #########");
}
catch (AuthenticationException e)
{
@@ -195,10 +196,8 @@ public class CascadeTracker extends AbstractTracker implements Tracker
}
finally
{
//System.out.println("###################: Releasing Cascade write lock");
getWriteLock().release();
}
} while(txBatch.size() > 0);
}
}
@@ -46,6 +46,8 @@ import org.alfresco.solr.NodeReport;
import org.alfresco.solr.TrackerState;
import org.alfresco.solr.client.SOLRAPIClient;
import org.apache.commons.lang3.StringUtils;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import java.util.HashMap;
import java.util.Optional;
@@ -63,6 +65,7 @@ import java.util.Properties;
*/
public abstract class CoreStatePublisher extends AbstractTracker
{
private static final Logger LOGGER = LoggerFactory.getLogger(CoreStatePublisher.class);
DocRouter docRouter;
private final boolean isMaster;
@@ -118,7 +121,7 @@ public abstract class CoreStatePublisher extends AbstractTracker
updateShardProperty();
if (shardProperty.isEmpty())
{
logger.warn("Sharding property {} was set to {}, but no such property was found.", SHARD_KEY_KEY, shardKeyName);
LOGGER.warn("Sharding property {} was set to {}, but no such property was found.", SHARD_KEY_KEY, shardKeyName);
}
});
}
@@ -134,11 +137,11 @@ public abstract class CoreStatePublisher extends AbstractTracker
{
if (updatedShardProperty.isEmpty())
{
logger.warn("The model defining {} property has been disabled", shardKeyName);
LOGGER.warn("The model defining {} property has been disabled", shardKeyName);
}
else
{
logger.info("New {} property found for {} ", SHARD_KEY_KEY, shardKeyName);
LOGGER.info("New {} property found for {}", SHARD_KEY_KEY, shardKeyName);
}
}
shardProperty = updatedShardProperty;
@@ -47,6 +47,8 @@ import org.alfresco.solr.client.SOLRAPIClient;
import org.alfresco.solr.config.ConfigUtil;
import org.apache.solr.core.SolrResourceLoader;
import org.json.JSONException;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
/**
* @startuml
@@ -82,6 +84,7 @@ import org.json.JSONException;
*/
public class ModelTracker extends AbstractTracker implements Tracker
{
private static final Logger LOGGER = LoggerFactory.getLogger(ModelTracker.class);
private final Set<StoreRef> indexedStores = new HashSet<>();
private final Set<StoreRef> ignoredStores = new HashSet<>();
@@ -106,7 +109,7 @@ public class ModelTracker extends AbstractTracker implements Tracker
super(p, client, coreName, informationServer, Tracker.Type.MODEL);
String normalSolrHome = SolrResourceLoader.normalizeDir(solrHome);
alfrescoModelDir = new File(ConfigUtil.locateProperty("solr.model.dir", normalSolrHome+"alfrescoModels"));
logger.info("Alfresco Model dir " + alfrescoModelDir);
LOGGER.info("Alfresco Model dir {}", alfrescoModelDir);
if (!alfrescoModelDir.exists())
{
alfrescoModelDir.mkdir();
@@ -197,7 +200,7 @@ public class ModelTracker extends AbstractTracker implements Tracker
int registeredSearcherCount = this.infoSrv.getRegisteredSearcherCount();
if (registeredSearcherCount >= getMaxLiveSearchers())
{
logger.info(".... skipping tracking registered searcher count = " + registeredSearcherCount);
LOGGER.info(".... skipping tracking registered searcher count = {}", registeredSearcherCount);
return;
}
@@ -268,7 +271,7 @@ public class ModelTracker extends AbstractTracker implements Tracker
}
catch (Throwable t)
{
logger.error("Model tracking failed for core: "+ coreName, t);
LOGGER.error("Model tracking failed for core: {}", coreName, t);
}
}
@@ -534,7 +537,7 @@ public class ModelTracker extends AbstractTracker implements Tracker
{
loadedModels.add(modelName);
}
logger.info("Loading model " + model.getName());
LOGGER.info("Loading model {}", model.getName());
}
}
@@ -26,6 +26,8 @@ import org.alfresco.solr.SolrInformationServer;
import org.alfresco.solr.TrackerState;
import org.alfresco.solr.client.SOLRAPIClient;
import org.apache.commons.codec.EncoderException;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import java.io.IOException;
import java.util.Properties;
@@ -47,6 +49,8 @@ import java.util.Properties;
*/
public class SlaveCoreStatePublisher extends CoreStatePublisher
{
private static final Logger LOGGER = LoggerFactory.getLogger(SlaveCoreStatePublisher.class);
public SlaveCoreStatePublisher(
boolean isMaster,
Properties coreProperties,
@@ -67,7 +71,7 @@ public class SlaveCoreStatePublisher extends CoreStatePublisher
}
catch (EncoderException | IOException | AuthenticationException exception )
{
logger.error("Unable to publish this node state. " +
LOGGER.error("Unable to publish this node state. " +
"A failure condition has been met during the outbound subscription message encoding process. " +
"See the stacktrace below for further details.", exception);
}