From e5e188350c740afe0890de9d235dc43de4b916ca Mon Sep 17 00:00:00 2001 From: Seth Smucker Date: Thu, 21 Mar 2024 12:17:27 -0400 Subject: [PATCH] Add TServer logging of query IDs and Tests Added the query option tserver.logging.active to enable logging of query IDs to the TServer logs. Created the class QueryLogIterator to handle this. Logs the start and end of each method called. Fixes #2305 --- .../java/datawave/query/QueryParameters.java | 1 + .../query/config/ShardQueryConfiguration.java | 29 ++- .../query/iterator/QueryLogIterator.java | 191 ++++++++++++++++++ .../datawave/query/iterator/QueryOptions.java | 6 - .../query/planner/DefaultQueryPlanner.java | 89 +++++++- .../query/tables/ShardQueryLogic.java | 8 + .../datawave/query/TserverLoggingTest.java | 124 ++++++++++++ .../config/ShardQueryConfigurationTest.java | 3 + .../query/iterator/QueryLogIteratorTest.java | 95 +++++++++ .../query/tables/ShardQueryLogicTest.java | 1 + .../datawave/query/QueryLogicFactory.xml | 2 + 11 files changed, 532 insertions(+), 17 deletions(-) create mode 100644 warehouse/query-core/src/main/java/datawave/query/iterator/QueryLogIterator.java create mode 100644 warehouse/query-core/src/test/java/datawave/query/TserverLoggingTest.java create mode 100644 warehouse/query-core/src/test/java/datawave/query/iterator/QueryLogIteratorTest.java diff --git a/warehouse/query-core/src/main/java/datawave/query/QueryParameters.java b/warehouse/query-core/src/main/java/datawave/query/QueryParameters.java index 9299c563089..be7d9a1a246 100644 --- a/warehouse/query-core/src/main/java/datawave/query/QueryParameters.java +++ b/warehouse/query-core/src/main/java/datawave/query/QueryParameters.java @@ -221,4 +221,5 @@ public class QueryParameters { * Used to specify model or DB fields that must be treated as strict (cannot be skipped if normalization fails) */ public static final String STRICT_FIELDS = "strict.fields"; + } diff --git a/warehouse/query-core/src/main/java/datawave/query/config/ShardQueryConfiguration.java b/warehouse/query-core/src/main/java/datawave/query/config/ShardQueryConfiguration.java index 2dbfdf655b4..0c2c8c96c7d 100644 --- a/warehouse/query-core/src/main/java/datawave/query/config/ShardQueryConfiguration.java +++ b/warehouse/query-core/src/main/java/datawave/query/config/ShardQueryConfiguration.java @@ -494,6 +494,11 @@ public class ShardQueryConfiguration extends GenericQueryConfiguration implement */ private boolean sortQueryByCounts = false; + /** + * Controls whether query IDs are logged on the tserver level via {@link datawave.query.iterator.QueryLogIterator}. + */ + private boolean tserverLoggingActive = true; + /** * Default constructor */ @@ -720,6 +725,7 @@ public ShardQueryConfiguration(ShardQueryConfiguration other) { this.setUseTermCounts(other.getUseTermCounts()); this.setSortQueryBeforeGlobalIndex(other.isSortQueryBeforeGlobalIndex()); this.setSortQueryByCounts(other.isSortQueryByCounts()); + this.setTserverLoggingActive(other.isTserverLoggingActive()); } /** @@ -2740,14 +2746,25 @@ public void setSortQueryByCounts(boolean sortQueryByCounts) { this.sortQueryByCounts = sortQueryByCounts; } + public boolean isTserverLoggingActive() { + return this.tserverLoggingActive; + } + + public void setTserverLoggingActive(boolean tserverLoggingActive) { + this.tserverLoggingActive = tserverLoggingActive; + } + @Override public boolean equals(Object o) { - if (this == o) + if (this == o) { return true; - if (o == null || getClass() != o.getClass()) + } + if (o == null || getClass() != o.getClass()) { return false; - if (!super.equals(o)) + } + if (!super.equals(o)) { return false; + } // @formatter:off ShardQueryConfiguration that = (ShardQueryConfiguration) o; return isTldQuery() == that.isTldQuery() && @@ -2947,7 +2964,8 @@ public boolean equals(Object o) { getUseFieldCounts() == that.getUseFieldCounts() && getUseTermCounts() == that.getUseTermCounts() && isSortQueryBeforeGlobalIndex() == that.isSortQueryBeforeGlobalIndex() && - isSortQueryByCounts() == that.isSortQueryByCounts(); + isSortQueryByCounts() == that.isSortQueryByCounts() && + isTserverLoggingActive() == that.isTserverLoggingActive(); // @formatter:on } @@ -3152,7 +3170,8 @@ public int hashCode() { getUseFieldCounts(), getUseTermCounts(), isSortQueryBeforeGlobalIndex(), - isSortQueryByCounts()); + isSortQueryByCounts(), + isTserverLoggingActive()); // @formatter:on } diff --git a/warehouse/query-core/src/main/java/datawave/query/iterator/QueryLogIterator.java b/warehouse/query-core/src/main/java/datawave/query/iterator/QueryLogIterator.java new file mode 100644 index 00000000000..efd54c8f103 --- /dev/null +++ b/warehouse/query-core/src/main/java/datawave/query/iterator/QueryLogIterator.java @@ -0,0 +1,191 @@ +package datawave.query.iterator; + +import static datawave.query.iterator.QueryOptions.QUERY_ID; + +import java.io.IOException; +import java.util.Collection; +import java.util.HashMap; +import java.util.Map; + +import org.apache.accumulo.core.data.ByteSequence; +import org.apache.accumulo.core.data.Key; +import org.apache.accumulo.core.data.Range; +import org.apache.accumulo.core.data.Value; +import org.apache.accumulo.core.iterators.IteratorEnvironment; +import org.apache.accumulo.core.iterators.OptionDescriber; +import org.apache.accumulo.core.iterators.SortedKeyValueIterator; +import org.apache.log4j.Logger; + +/** + * An iterator used to log the start and end of each method run by the {@link SortedKeyValueIterator} above it in the iterator stack. Logs the QueryID + * associated with each method. Logs are written on the TServer where the iterator is running + */ +public class QueryLogIterator implements SortedKeyValueIterator, OptionDescriber { + + private static final Logger log = Logger.getLogger(QueryLogIterator.class); + private static final String CLASS_NAME = QueryLogIterator.class.getSimpleName(); + + private String queryID; + private SortedKeyValueIterator source; + private IteratorEnvironment env; + + /** + * Default constructor + */ + public QueryLogIterator() { + // no-arg constructor + } + + /** + * Class copy constructor + */ + public QueryLogIterator(QueryLogIterator other, IteratorEnvironment env) { + this.source = other.source.deepCopy(env); + this.env = other.env; + this.queryID = other.queryID; + } + + /** + * Wraps the init() method of the iterator above it, logging the start and end of the method along with its query id. + */ + @Override + public void init(SortedKeyValueIterator source, Map options, IteratorEnvironment env) throws IOException { + + try { + logStartOf("init()"); + this.queryID = options.get(QUERY_ID); + this.source = source; + this.env = env; + } finally { + logEndOf("init()"); + } + } + + /** + * Logs the query id and {@link SortedKeyValueIterator} method name before the method is run. + */ + private void logStartOf(String methodName) { + if (log.isInfoEnabled()) { + log.info(CLASS_NAME + " " + methodName + " Started QueryID: " + this.queryID); + } + } + + /** + * Logs the query id and {@link SortedKeyValueIterator} method name after the method is run. + */ + private void logEndOf(String methodName) { + if (log.isInfoEnabled()) { + log.info(CLASS_NAME + " " + methodName + " Ended QueryID: " + this.queryID); + } + } + + /** + * Wraps the hasTop() method of the iterator above it, logging the start and end of the method along with its query id. + */ + @Override + public boolean hasTop() { + boolean result; + + try { + logStartOf("hasTop()"); + result = source.hasTop(); + } finally { + logEndOf("hasTop()"); + } + return result; + } + + /** + * Wraps the next() method of the iterator above it, logging the start and end of the method along with its query id. + */ + @Override + public void next() throws IOException { + try { + logStartOf("next()"); + source.next(); + } finally { + logEndOf("next()"); + } + } + + /** + * Wraps the getTopKey() method of the iterator above it, logging the start and end of the method along with its query id. + */ + @Override + public Key getTopKey() { + Key k; + try { + logStartOf("getTopKey()"); + k = source.getTopKey(); + } finally { + logEndOf("getTopKey()"); + } + return k; + } + + /** + * Wraps the getTopValue() method of the iterator above it, logging the start and end of the method along with its query id. + */ + @Override + public Value getTopValue() { + Value v; + try { + logStartOf("getTopValue()"); + v = source.getTopValue(); + } finally { + logEndOf("getTopValue()"); + } + return v; + } + + /** + * Wraps the deepCopy() method of the iterator above it, logging the start and end of the method along with its query id. + */ + @Override + public SortedKeyValueIterator deepCopy(IteratorEnvironment iteratorEnvironment) { + + QueryLogIterator copy; + + try { + logStartOf("deepCopy()"); + copy = new QueryLogIterator(this, this.env); + } finally { + logEndOf("deepCopy()"); + } + return copy; + } + + /** + * Wraps the seek() method of the iterator above it, logging the start and end of the method along with its query id. + */ + @Override + public void seek(Range range, Collection collection, boolean b) throws IOException { + + try { + logStartOf("seek()"); + this.source.seek(range, collection, b); + } finally { + logEndOf("seek()"); + } + } + + /** + * Returns a {@link org.apache.accumulo.core.iterators.OptionDescriber.IteratorOptions} object containing a description of the iterator and an option for + * the QueryID. + */ + @Override + public IteratorOptions describeOptions() { + Map options = new HashMap<>(); + options.put(QUERY_ID, "The QueryID to be logged as methods are invoked"); + + return new IteratorOptions(getClass().getSimpleName(), "An iterator used to log the QueryID", options, null); + } + + /** + * Returns true if the options provided contains the QueryID. + */ + @Override + public boolean validateOptions(Map options) { + return options.containsKey(QUERY_ID); + } +} diff --git a/warehouse/query-core/src/main/java/datawave/query/iterator/QueryOptions.java b/warehouse/query-core/src/main/java/datawave/query/iterator/QueryOptions.java index 0f108147785..3e0162e14d7 100644 --- a/warehouse/query-core/src/main/java/datawave/query/iterator/QueryOptions.java +++ b/warehouse/query-core/src/main/java/datawave/query/iterator/QueryOptions.java @@ -21,7 +21,6 @@ import java.util.Map; import java.util.Map.Entry; import java.util.Set; -import java.util.TreeSet; import java.util.stream.Collectors; import java.util.zip.GZIPInputStream; import java.util.zip.GZIPOutputStream; @@ -39,12 +38,7 @@ import org.apache.log4j.Logger; import org.apache.zookeeper.server.quorum.QuorumPeerConfig.ConfigException; -import com.esotericsoftware.kryo.Kryo; -import com.esotericsoftware.kryo.io.Input; -import com.esotericsoftware.kryo.io.Output; import com.fasterxml.jackson.core.JsonProcessingException; -import com.fasterxml.jackson.core.type.TypeReference; -import com.fasterxml.jackson.databind.ObjectMapper; import com.google.common.base.CharMatcher; import com.google.common.base.Function; import com.google.common.base.Predicate; diff --git a/warehouse/query-core/src/main/java/datawave/query/planner/DefaultQueryPlanner.java b/warehouse/query-core/src/main/java/datawave/query/planner/DefaultQueryPlanner.java index 3c7fd8ce575..a7a0fd874ae 100644 --- a/warehouse/query-core/src/main/java/datawave/query/planner/DefaultQueryPlanner.java +++ b/warehouse/query-core/src/main/java/datawave/query/planner/DefaultQueryPlanner.java @@ -90,6 +90,7 @@ import datawave.query.index.lookup.RangeStream; import datawave.query.iterator.CloseableListIterable; import datawave.query.iterator.QueryIterator; +import datawave.query.iterator.QueryLogIterator; import datawave.query.iterator.QueryOptions; import datawave.query.iterator.ivarator.IvaratorCacheDirConfig; import datawave.query.iterator.logic.IndexIterator; @@ -254,6 +255,7 @@ public class DefaultQueryPlanner extends QueryPlanner implements Cloneable { private List transformRules = Lists.newArrayList(); protected Class> queryIteratorClazz = QueryIterator.class; + protected Class> queryLogIteratorClazz = QueryLogIterator.class; protected String plannedScript = null; @@ -272,6 +274,7 @@ public class DefaultQueryPlanner extends QueryPlanner implements Cloneable { protected ExecutorService builderThread = null; protected Future settingFuture = null; + protected Future logSettingFuture = null; protected long maxRangeWaitMillis = 125; @@ -330,6 +333,7 @@ protected DefaultQueryPlanner(DefaultQueryPlanner other) { setDisableExpandIndexFunction(other.disableExpandIndexFunction); rules.addAll(other.rules); queryIteratorClazz = other.queryIteratorClazz; + queryLogIteratorClazz = other.queryLogIteratorClazz; setMetadataHelper(other.getMetadataHelper()); setDateIndexHelper(other.getDateIndexHelper()); setCompressOptionMappings(other.getCompressOptionMappings()); @@ -407,11 +411,16 @@ public CloseableIterable process(GenericQueryConfiguration genericCon protected CloseableIterable process(ScannerFactory scannerFactory, MetadataHelper metadataHelper, DateIndexHelper dateIndexHelper, ShardQueryConfiguration config, String query, Query settings) throws DatawaveQueryException { settingFuture = null; + logSettingFuture = null; IteratorSetting cfg = null; + IteratorSetting logCfg = null; if (preloadOptions) { cfg = getQueryIterator(metadataHelper, config, settings, "", false, true); + if (config.isTserverLoggingActive()) { + logCfg = getQueryLogIterator(config, settings); + } } try { @@ -453,8 +462,9 @@ protected CloseableIterable process(ScannerFactory scannerFactory, Me // Set the final query after we're done mucking with it String newQueryString = JexlStringBuildingVisitor.buildQuery(config.getQueryTree()); - if (log.isTraceEnabled()) + if (log.isTraceEnabled()) { log.trace("newQueryString is " + newQueryString); + } if (StringUtils.isBlank(newQueryString)) { stopwatch.stop(); QueryException qe = new QueryException(DatawaveErrorCode.EMPTY_QUERY_STRING_AFTER_MODIFICATION); @@ -469,9 +479,21 @@ protected CloseableIterable process(ScannerFactory scannerFactory, Me cfg = getQueryIterator(metadataHelper, config, settings, "", false, false); } configureIterator(config, cfg, newQueryString, isFullTable); + + while (config.isTserverLoggingActive() && null == logCfg) { + logCfg = getQueryLogIterator(config, settings); + if (logSettingFuture.isDone()) { + // It's possible that getQueryLogIterator will return a non-null setting once we know the future is done. Check one more time. + if (logCfg == null) { + logCfg = getQueryLogIterator(config, settings); + } + break; + } + } } - final QueryData queryData = new QueryData().withQuery(newQueryString).withSettings(Lists.newArrayList(cfg)); + List iteratorSettings = logCfg == null ? Collections.singletonList(cfg) : Lists.newArrayList(cfg, logCfg); + final QueryData queryData = new QueryData().withQuery(newQueryString).withSettings(iteratorSettings); stopwatch.stop(); @@ -2140,12 +2162,15 @@ protected void configureAdditionalOptions(ShardQueryConfiguration config, Iterat // no-op } + private static final int QUERY_ITERATOR_PRIORITY_ADDEND = 40; + protected Future loadQueryIterator(final MetadataHelper metadataHelper, final ShardQueryConfiguration config, final Query settings, final String queryString, final Boolean isFullTable, boolean isPreload) throws DatawaveQueryException { return builderThread.submit(() -> { + // VersioningIterator is typically set at 20 on the table - IteratorSetting cfg = new IteratorSetting(config.getBaseIteratorPriority() + 40, "query", getQueryIteratorClass()); + IteratorSetting cfg = new IteratorSetting(config.getBaseIteratorPriority() + QUERY_ITERATOR_PRIORITY_ADDEND, "query", getQueryIteratorClass()); addOption(cfg, Constants.RETURN_TYPE, config.getReturnType().toString(), false); addOption(cfg, QueryOptions.FULL_TABLE_SCAN_ONLY, Boolean.toString(isFullTable), false); @@ -2237,6 +2262,23 @@ protected Future loadQueryIterator(final MetadataHelper metadat }); } + private static final int QUERY_LOG_ITERATOR_PRIORITY_ADDEND = QUERY_ITERATOR_PRIORITY_ADDEND + 1; + + protected Future loadQueryLogIterator(final ShardQueryConfiguration config, final Query settings) { + return builderThread.submit(() -> { + // Create the query log iterator only if tserver logging should be active. + if (config.isTserverLoggingActive()) { + // VersioningIterator is typically set at 20 on the table + IteratorSetting cfg = new IteratorSetting(config.getBaseIteratorPriority() + QUERY_LOG_ITERATOR_PRIORITY_ADDEND, "queryLog", + getQueryLogIteratorClass()); + addOption(cfg, QueryOptions.QUERY_ID, settings.getId().toString(), false); + return cfg; + } else { + return null; + } + }); + } + /** * Load indexed, index only, and composite fields into the query iterator * @@ -2347,16 +2389,43 @@ private List getShuffledIvaratoCacheDirConfigs(ShardQuer */ protected IteratorSetting getQueryIterator(MetadataHelper metadataHelper, ShardQueryConfiguration config, Query settings, String queryString, Boolean isFullTable, boolean isPreload) throws DatawaveQueryException { - if (null == settingFuture) + if (null == settingFuture) { settingFuture = loadQueryIterator(metadataHelper, config, settings, queryString, isFullTable, isPreload); - if (settingFuture.isDone()) + } + if (settingFuture.isDone()) { try { return settingFuture.get(); } catch (InterruptedException | ExecutionException e) { throw new RuntimeException(e.getCause()); } - else + } else { + return null; + } + } + + /** + * Get the loaded {@link IteratorSetting} + * + * @param config + * the {@link ShardQueryConfiguration} + * @param settings + * the {@link Query} + * @return a loaded {@link IteratorSetting} + */ + protected IteratorSetting getQueryLogIterator(ShardQueryConfiguration config, Query settings) { + if (null == logSettingFuture) { + logSettingFuture = loadQueryLogIterator(config, settings); + } + + if (logSettingFuture.isDone()) { + try { + return logSettingFuture.get(); + } catch (InterruptedException | ExecutionException e) { + throw new RuntimeException(e.getCause()); + } + } else { return null; + } } public static void configureTypeMappings(ShardQueryConfiguration config, IteratorSetting cfg, MetadataHelper metadataHelper, boolean compressMappings) @@ -3061,6 +3130,14 @@ public void setQueryIteratorClass(Class> getQueryLogIteratorClass() { + return queryLogIteratorClazz; + } + + public void setQueryLogIteratorClass(Class> clazz) { + queryLogIteratorClazz = clazz; + } + public void setPreloadOptions(boolean preloadOptions) { this.preloadOptions = preloadOptions; } diff --git a/warehouse/query-core/src/main/java/datawave/query/tables/ShardQueryLogic.java b/warehouse/query-core/src/main/java/datawave/query/tables/ShardQueryLogic.java index 4ce5f1c1b8e..bd280f5b411 100644 --- a/warehouse/query-core/src/main/java/datawave/query/tables/ShardQueryLogic.java +++ b/warehouse/query-core/src/main/java/datawave/query/tables/ShardQueryLogic.java @@ -2929,4 +2929,12 @@ public boolean isRebuildDatatypeFilterPerShard() { public void setRebuildDatatypeFilterPerShard(boolean rebuildDatatypeFilterPerShard) { getConfig().setRebuildDatatypeFilterPerShard(rebuildDatatypeFilterPerShard); } + + public boolean isTserverLoggingActive() { + return getConfig().isTserverLoggingActive(); + } + + public void setTserverLoggingActive(boolean tserverLoggingActive) { + getConfig().setTserverLoggingActive(tserverLoggingActive); + } } diff --git a/warehouse/query-core/src/test/java/datawave/query/TserverLoggingTest.java b/warehouse/query-core/src/test/java/datawave/query/TserverLoggingTest.java new file mode 100644 index 00000000000..8281279f873 --- /dev/null +++ b/warehouse/query-core/src/test/java/datawave/query/TserverLoggingTest.java @@ -0,0 +1,124 @@ +package datawave.query; + +import static datawave.query.testframework.CitiesDataType.CityEntry; +import static datawave.query.testframework.CitiesDataType.CityField; +import static datawave.query.testframework.CitiesDataType.getManager; +import static datawave.query.testframework.CitiesDataType.getTestAuths; +import static datawave.query.testframework.RawDataManager.EQ_OP; + +import java.util.Collections; +import java.util.HashMap; +import java.util.HashSet; +import java.util.Iterator; +import java.util.Map; +import java.util.Set; +import java.util.UUID; + +import org.apache.accumulo.core.client.IteratorSetting; +import org.apache.accumulo.core.security.Authorizations; +import org.apache.log4j.Logger; +import org.junit.After; +import org.junit.Assert; +import org.junit.BeforeClass; +import org.junit.ClassRule; +import org.junit.Test; + +import datawave.core.query.configuration.QueryData; +import datawave.microservice.query.QueryImpl; +import datawave.query.iterator.QueryLogIterator; +import datawave.query.testframework.AbstractFunctionalQuery; +import datawave.query.testframework.AccumuloSetup; +import datawave.query.testframework.CitiesDataType; +import datawave.query.testframework.FieldConfig; +import datawave.query.testframework.FileType; +import datawave.query.testframework.GenericCityFields; + +public class TserverLoggingTest extends AbstractFunctionalQuery { + + @ClassRule + public static AccumuloSetup accumuloSetup = new AccumuloSetup(); + private static final Logger log = Logger.getLogger(TserverLoggingTest.class); + + private final Set authSet = Collections.singleton(getTestAuths()); + + @BeforeClass + public static void filterSetup() throws Exception { + FieldConfig generic = new GenericCityFields(); + Set comp = new HashSet<>(); + comp.add(CityField.CITY.name()); + comp.add(CityField.COUNTRY.name()); + generic.addCompositeField(comp); + generic.addIndexField(CityField.COUNTRY.name()); + generic.addIndexOnlyField(CityField.STATE.name()); + + accumuloSetup.setData(FileType.CSV, new CitiesDataType(CityEntry.generic, generic)); + client = accumuloSetup.loadTables(log); + } + + public TserverLoggingTest() { + super(getManager()); + } + + @After + public void tearDown() throws Exception { + this.logic = null; + } + + /** + * Verify that when tserver logging active is set to false via the config, that the {@link QueryLogIterator} is not added to the iterator stack. + */ + @Test + public void testTserverLoggingActiveFalseConfig() throws Exception { + logic.getConfig().setTserverLoggingActive(false); + + initializeQuery(Collections.emptyMap()); + + assertQueryLogIteratorPresence(false); + } + + /** + * Verify that when tserver logging active is set to true via the config, that the {@link QueryLogIterator} is added to the iterator stack. + */ + @Test + public void testTserverLoggingActiveTrueConfig() throws Exception { + logic.getConfig().setTserverLoggingActive(true); + + initializeQuery(Collections.emptyMap()); + + assertQueryLogIteratorPresence(true); + } + + private void initializeQuery(Map options) throws Exception { + String query = CityField.STATE.name() + EQ_OP + "'ohio'"; + + QueryImpl q = new QueryImpl(); + q.setBeginDate(this.dataManager.getShardStartEndDate()[0]); + q.setEndDate(this.dataManager.getShardStartEndDate()[1]); + q.setQuery(query); + q.setParameters(options); + + q.setId(UUID.randomUUID()); + q.setPagesize(Integer.MAX_VALUE); + q.setQueryAuthorizations(auths.toString()); + this.logic.initialize(client, q, authSet); + } + + private void assertQueryLogIteratorPresence(boolean presenceRequired) { + // Fetch the query data. + Iterator iterator = this.logic.getConfig().getQueriesIter(); + while (iterator.hasNext()) { + QueryData queryData = iterator.next(); + Assert.assertEquals(presenceRequired, isQueryLogIteratorPresent(queryData)); + } + } + + private boolean isQueryLogIteratorPresent(QueryData data) { + return data.getSettings().stream().map(IteratorSetting::getIteratorClass).anyMatch(c -> c.equals(QueryLogIterator.class.getName())); + } + + @Override + protected void testInit() { + this.auths = getTestAuths(); + this.documentKey = CityField.EVENT_ID.name(); + } +} diff --git a/warehouse/query-core/src/test/java/datawave/query/config/ShardQueryConfigurationTest.java b/warehouse/query-core/src/test/java/datawave/query/config/ShardQueryConfigurationTest.java index 895a2cbae9f..d49b16775ab 100644 --- a/warehouse/query-core/src/test/java/datawave/query/config/ShardQueryConfigurationTest.java +++ b/warehouse/query-core/src/test/java/datawave/query/config/ShardQueryConfigurationTest.java @@ -585,6 +585,9 @@ public void setUp() throws Exception { updatedValues.put("tableConsistencyLevels", Collections.singletonMap(TableName.SHARD, ScannerBase.ConsistencyLevel.EVENTUAL)); defaultValues.put("tableHints", Collections.emptyMap()); updatedValues.put("tableHints", Collections.emptyMap()); + + defaultValues.put("tserverLoggingActive", true); + updatedValues.put("tserverLoggingActive", false); } private Query createQuery(String query) { diff --git a/warehouse/query-core/src/test/java/datawave/query/iterator/QueryLogIteratorTest.java b/warehouse/query-core/src/test/java/datawave/query/iterator/QueryLogIteratorTest.java new file mode 100644 index 00000000000..7452b3f221e --- /dev/null +++ b/warehouse/query-core/src/test/java/datawave/query/iterator/QueryLogIteratorTest.java @@ -0,0 +1,95 @@ +package datawave.query.iterator; + +import java.io.File; +import java.util.Collections; +import java.util.Map; +import java.util.Objects; +import java.util.Set; + +import org.apache.accumulo.core.client.AccumuloClient; +import org.apache.accumulo.core.client.BatchWriter; +import org.apache.accumulo.core.client.BatchWriterConfig; +import org.apache.accumulo.core.client.IteratorSetting; +import org.apache.accumulo.core.client.MutationsRejectedException; +import org.apache.accumulo.core.client.Scanner; +import org.apache.accumulo.core.client.TableNotFoundException; +import org.apache.accumulo.core.data.Key; +import org.apache.accumulo.core.data.Mutation; +import org.apache.accumulo.core.data.Range; +import org.apache.accumulo.core.data.Value; +import org.apache.accumulo.core.security.Authorizations; +import org.apache.log4j.Level; +import org.apache.log4j.Logger; +import org.junit.After; +import org.junit.Before; +import org.junit.BeforeClass; +import org.junit.Test; + +import datawave.accumulo.inmemory.InMemoryAccumuloClient; +import datawave.accumulo.inmemory.InMemoryInstance; +import datawave.security.util.ScannerHelper; + +/** + * Unit test for {@link QueryLogIterator}. + */ +public class QueryLogIteratorTest { + + private static final String TABLE_NAME = "testTable"; + private static final String[] AUTHS = {"FOO", "BAR", "COB"}; + private final Value BLANK_VALUE = new Value(new byte[0]); + private final Set AUTHS_SET = Collections.singleton(new Authorizations(AUTHS)); + + private AccumuloClient accumuloClient; + + @BeforeClass + public static void beforeClass() throws Exception { + File dir = new File(Objects.requireNonNull(ClassLoader.getSystemClassLoader().getResource(".")).toURI()); + File targetDir = dir.getParentFile(); + System.setProperty("hadoop.home.dir", targetDir.getAbsolutePath()); + } + + @Before + public void setUp() throws Exception { + accumuloClient = new InMemoryAccumuloClient("root", new InMemoryInstance(QueryLogIteratorTest.class.toString())); + if (!accumuloClient.tableOperations().exists(TABLE_NAME)) { + accumuloClient.tableOperations().create(TABLE_NAME); + } + + BatchWriterConfig config = new BatchWriterConfig(); + config.setMaxMemory(1000L); + try (BatchWriter writer = accumuloClient.createBatchWriter(TABLE_NAME, config)) { + Mutation mutation = new Mutation("fieldA"); + mutation.put("boo", "a", BLANK_VALUE); + mutation.put("boo", "b", BLANK_VALUE); + mutation.put("foo", "a", BLANK_VALUE); + mutation.put("foo", "c", BLANK_VALUE); + writer.addMutation(mutation); + writer.flush(); + } catch (MutationsRejectedException | TableNotFoundException e) { + throw new RuntimeException(e); + } + } + + @After + public void tearDown() throws Exception { + accumuloClient.tableOperations().deleteRows(TABLE_NAME, null, null); + } + + @Test + public void testLogging() throws TableNotFoundException { + Logger.getRootLogger().setLevel(Level.INFO); + + Scanner scanner = ScannerHelper.createScanner(accumuloClient, TABLE_NAME, AUTHS_SET); + scanner.setRange(new Range()); + + IteratorSetting iteratorSetting = new IteratorSetting(10, QueryLogIterator.class); + iteratorSetting.addOption(QueryOptions.QUERY_ID, "12345"); + scanner.addScanIterator(iteratorSetting); + + for (Map.Entry entry : scanner) { + // Do nothing here, we are examining logs only. + } + + // Logs will print to console with a start/end for each method in the iterator. + } +} diff --git a/warehouse/query-core/src/test/java/datawave/query/tables/ShardQueryLogicTest.java b/warehouse/query-core/src/test/java/datawave/query/tables/ShardQueryLogicTest.java index 8a0be8427ed..62e479ebae8 100644 --- a/warehouse/query-core/src/test/java/datawave/query/tables/ShardQueryLogicTest.java +++ b/warehouse/query-core/src/test/java/datawave/query/tables/ShardQueryLogicTest.java @@ -360,4 +360,5 @@ public void testNegativeFilterRegexV2() throws Exception { runTestQuery(expected, queryString, format.parse("20091231"), format.parse("20150101"), extraParameters); } + } diff --git a/web-services/deploy/configuration/src/main/resources/datawave/query/QueryLogicFactory.xml b/web-services/deploy/configuration/src/main/resources/datawave/query/QueryLogicFactory.xml index 5adce1647d0..fc51de1c4c4 100644 --- a/web-services/deploy/configuration/src/main/resources/datawave/query/QueryLogicFactory.xml +++ b/web-services/deploy/configuration/src/main/resources/datawave/query/QueryLogicFactory.xml @@ -323,6 +323,8 @@ + +