From 99cdf557b3a397fdd5cbb0a7afe1a340001a4f81 Mon Sep 17 00:00:00 2001 From: Andreas Huber Date: Wed, 6 Feb 2019 15:51:41 +0000 Subject: [PATCH] add metric logger for query completion evaluation --- .../lang/FindValuesForQueryCompletion.java | 77 +++++++++++++------ 1 file changed, 54 insertions(+), 23 deletions(-) diff --git a/data-store/src/main/java/org/lucares/pdb/datastore/lang/FindValuesForQueryCompletion.java b/data-store/src/main/java/org/lucares/pdb/datastore/lang/FindValuesForQueryCompletion.java index b25a742..3b5f447 100644 --- a/data-store/src/main/java/org/lucares/pdb/datastore/lang/FindValuesForQueryCompletion.java +++ b/data-store/src/main/java/org/lucares/pdb/datastore/lang/FindValuesForQueryCompletion.java @@ -15,9 +15,17 @@ import org.lucares.pdb.datastore.lang.Expression.Not; import org.lucares.pdb.datastore.lang.Expression.Or; import org.lucares.pdb.datastore.lang.Expression.Property; import org.lucares.utils.CollectionUtils; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; public class FindValuesForQueryCompletion extends ExpressionVisitor> { + private static final Logger METRIC_AND_CARET_LOGGER = LoggerFactory + .getLogger("org.lucares.metrics.queryCompletion.expressionEvaluation.andCaret"); + + private static final Logger METRIC_LOGGER = LoggerFactory + .getLogger("org.lucares.metrics.queryCompletion.expressionEvaluation"); + private static final class AndCaretExpressionVisitor extends ExpressionVisitor> { private final QueryCompletionIndex index; private final String field; @@ -29,16 +37,18 @@ public class FindValuesForQueryCompletion extends ExpressionVisitor visit(final Property property) { - + final long start = System.nanoTime(); final String fieldA = property.getProperty(); final String valueA = property.getValue().getValue(); - return index.find(fieldA, valueA, field); + SortedSet result = index.find(fieldA, valueA, field); + METRIC_AND_CARET_LOGGER.debug("{}: {}ms", property, (System.nanoTime() - start) / 1_000_000.0); + return result; } @Override public SortedSet visit(final InExpression expression) { - + final long start = System.nanoTime(); final SortedSet result = new TreeSet<>(); final String property = expression.getProperty(); final List values = expression.getValues(); @@ -46,39 +56,45 @@ public class FindValuesForQueryCompletion extends ExpressionVisitor candidates = index.find(property, value, field); result.addAll(candidates); } - + METRIC_AND_CARET_LOGGER.debug("{}: {}ms", expression, (System.nanoTime() - start) / 1_000_000.0); return result; } @Override public SortedSet visit(final And expression) { + final long start = System.nanoTime(); + try { + final Expression left = expression.getLeft(); + final Expression right = expression.getRight(); - final Expression left = expression.getLeft(); - final Expression right = expression.getRight(); + if (left instanceof Property && right instanceof Not) { + final Property leftProperty = (Property) left; - if (left instanceof Property && right instanceof Not) { - final Property leftProperty = (Property) left; + final SortedSet allValuesForField = leftProperty.visit(this); - final SortedSet allValuesForField = leftProperty.visit(this); + final Expression rightInnerExpression = ((Not) right).getExpression(); + final SortedSet rightResult = rightInnerExpression.visit(this); - final Expression rightInnerExpression = ((Not) right).getExpression(); - final SortedSet rightResult = rightInnerExpression.visit(this); + return CollectionUtils.removeAll(allValuesForField, rightResult, TreeSet::new); - return CollectionUtils.removeAll(allValuesForField, rightResult, TreeSet::new); + } else { - } else { + final SortedSet result = left.visit(this); + final SortedSet rightResult = right.visit(this); - final SortedSet result = left.visit(this); - final SortedSet rightResult = right.visit(this); + result.retainAll(rightResult); - result.retainAll(rightResult); - - return result; + return result; + } + } finally { + METRIC_AND_CARET_LOGGER.debug("{}: {}ms", expression, (System.nanoTime() - start) / 1_000_000.0); } } @Override public SortedSet visit(final Or expression) { + + final long start = System.nanoTime(); final Expression left = expression.getLeft(); final Expression right = expression.getRight(); @@ -87,12 +103,14 @@ public class FindValuesForQueryCompletion extends ExpressionVisitor visit(final Not expression) { + final long start = System.nanoTime(); if (!(expression.getExpression() instanceof Property)) { throw new UnsupportedOperationException("NOT expressions like '" + expression + "' are not supported. Only 'NOT property=value' expressions are supported."); @@ -109,6 +127,7 @@ public class FindValuesForQueryCompletion extends ExpressionVisitor result = CollectionUtils.removeAll(valuesNotForField, valuesOnlyAvailableInField, TreeSet::new); + METRIC_AND_CARET_LOGGER.debug("{}: {}ms", expression, (System.nanoTime() - start) / 1_000_000.0); return result; } } @@ -122,6 +141,7 @@ public class FindValuesForQueryCompletion extends ExpressionVisitor visit(final Property property) { + final long start = System.nanoTime(); final String field = property.getProperty(); final String value = property.getValue().getValue(); @@ -129,12 +149,15 @@ public class FindValuesForQueryCompletion extends ExpressionVisitor result = GloblikePattern.filterValues(allValuesForField, valuePrefix, TreeSet::new); + METRIC_LOGGER.debug("{}: {}ms", property, (System.nanoTime() - start) / 1_000_000.0); + return result; } @Override public SortedSet visit(final AndCaretExpression expression) { + final long start = System.nanoTime(); final Property caretExpression = expression.getCaretExpression(); final String field = caretExpression.getProperty(); final String valueWithCaretMarker = caretExpression.getValue().getValue(); @@ -146,12 +169,16 @@ public class FindValuesForQueryCompletion extends ExpressionVisitor candidateValues = rightHandExpression .visit(new AndCaretExpressionVisitor(queryCompletionIndex, field)); - return GloblikePattern.filterValues(candidateValues, valuePrefix, TreeSet::new); + final TreeSet result = GloblikePattern.filterValues(candidateValues, valuePrefix, TreeSet::new); + + METRIC_LOGGER.debug("{}: {}ms", expression, (System.nanoTime() - start) / 1_000_000.0); + return result; } @Override public SortedSet visit(final AndNotCaretExpression expression) { + final long start = System.nanoTime(); final Property caretExpression = expression.getCaretExpression(); final String field = caretExpression.getProperty(); final String valueWithCaretMarker = caretExpression.getValue().getValue(); @@ -174,6 +201,7 @@ public class FindValuesForQueryCompletion extends ExpressionVisitor result = CollectionUtils.retainAll(rightHandValues, valuesForFieldMatchingCaretExpression, TreeSet::new); + METRIC_LOGGER.debug("{}: {}ms", expression, (System.nanoTime() - start) / 1_000_000.0); return result; } @@ -183,6 +211,7 @@ public class FindValuesForQueryCompletion extends ExpressionVisitor allValuesForField = queryCompletionIndex.findAllValuesForField(field); final String valueWithCaretMarker = ((Property) innerExpression).getValue().getValue(); @@ -190,6 +219,7 @@ public class FindValuesForQueryCompletion extends ExpressionVisitor result = GloblikePattern.filterValues(allValuesForField, valuePrefix + "*", TreeSet::new); + METRIC_LOGGER.debug("{}: {}ms", expression, (System.nanoTime() - start) / 1_000_000.0); return result; } else { throw new UnsupportedOperationException(); @@ -198,6 +228,7 @@ public class FindValuesForQueryCompletion extends ExpressionVisitor visit(final Or expression) { + final long start = System.nanoTime(); final Expression left = expression.getLeft(); final Expression right = expression.getRight(); @@ -205,13 +236,13 @@ public class FindValuesForQueryCompletion extends ExpressionVisitor rightResult = right.visit(this); result.addAll(rightResult); - + METRIC_LOGGER.debug("{}: {}ms", expression, (System.nanoTime() - start) / 1_000_000.0); return result; } @Override public SortedSet visit(final And expression) { - + final long start = System.nanoTime(); final Expression left = expression.getLeft(); final Expression right = expression.getRight(); @@ -219,7 +250,7 @@ public class FindValuesForQueryCompletion extends ExpressionVisitor rightResult = right.visit(this); result.retainAll(rightResult); - + METRIC_LOGGER.debug("{}: {}ms", expression, (System.nanoTime() - start) / 1_000_000.0); return result; } }