From 8640e3e551b8ceb0718d52fcb9416e62444b20be Mon Sep 17 00:00:00 2001 From: Adam Retter Date: Wed, 4 Oct 2023 15:38:34 +0100 Subject: [PATCH 1/3] [refactor] Cleanup XQuery Pragma code --- .../java/org/exist/xquery/AbstractPragma.java | 98 ++++++++ .../org/exist/xquery/ExtensionExpression.java | 56 ++--- .../main/java/org/exist/xquery/Optimizer.java | 7 +- .../main/java/org/exist/xquery/Pragma.java | 59 ++--- .../java/org/exist/xquery/XQueryContext.java | 2 +- .../exist/xquery/pragmas/ForceIndexUse.java | 59 ++--- .../exist/xquery/pragmas/NoIndexPragma.java | 35 +-- .../org/exist/xquery/pragmas/Optimize.java | 236 +++++++++--------- .../exist/xquery/pragmas/ProfilePragma.java | 30 +-- .../org/exist/xquery/pragmas/TimerPragma.java | 59 ++--- .../modules/range/OptimizeFieldPragma.java | 71 ++---- 11 files changed, 357 insertions(+), 355 deletions(-) create mode 100644 exist-core/src/main/java/org/exist/xquery/AbstractPragma.java diff --git a/exist-core/src/main/java/org/exist/xquery/AbstractPragma.java b/exist-core/src/main/java/org/exist/xquery/AbstractPragma.java new file mode 100644 index 00000000000..bd96758ba10 --- /dev/null +++ b/exist-core/src/main/java/org/exist/xquery/AbstractPragma.java @@ -0,0 +1,98 @@ +/* + * eXist-db Open Source Native XML Database + * Copyright (C) 2001 The eXist-db Authors + * + * info@exist-db.org + * http://www.exist-db.org + * + * This library is free software; you can redistribute it and/or + * modify it under the terms of the GNU Lesser General Public + * License as published by the Free Software Foundation; either + * version 2.1 of the License, or (at your option) any later version. + * + * This library is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU + * Lesser General Public License for more details. + * + * You should have received a copy of the GNU Lesser General Public + * License along with this library; if not, write to the Free Software + * Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA + */ +package org.exist.xquery; + +import org.exist.dom.QName; +import org.exist.xquery.util.ExpressionDumper; +import org.exist.xquery.value.Item; +import org.exist.xquery.value.Sequence; + +import javax.annotation.Nullable; + +/** + * Base class for implementing an XQuery Pragma expression. + * + * @author Adam Retter + */ +public abstract class AbstractPragma implements Pragma { + private final QName name; + private @Nullable final String contents; + private @Nullable final Expression expression; + + public AbstractPragma(@Nullable final Expression expression, final QName name, @Nullable final String contents) { + this.expression = expression; + this.name = name; + this.contents = contents; + } + + @Override + public QName getName() { + return name; + } + + public @Nullable Expression getExpression() { + return expression; + } + + @Override + public void analyze(final AnalyzeContextInfo contextInfo) throws XPathException { + // no-op by default + } + + @Override + public void before(final XQueryContext context, @Nullable final Expression expression, final Sequence contextSequence) throws XPathException { + // no-op by default + } + + @Override + public Sequence eval(final Sequence contextSequence, final Item contextItem) throws XPathException { + // no-op by default + return null; + } + + @Override + public void after(final XQueryContext context, @Nullable final Expression expression) throws XPathException { + // no-op by default + } + + protected @Nullable String getContents() { + return contents; + } + + @Override + public void dump(final ExpressionDumper dumper) { + dumper.display("(# " + getName().getStringValue()); + if (getContents() != null) { + dumper.display(' ').display(getContents()); + } + } + + @Override + public void resetState(final boolean postOptimization) { + //no-op by default + } + + @Override + public String toString() { + return "(# " + name + ' ' + contents + "#)"; + } +} diff --git a/exist-core/src/main/java/org/exist/xquery/ExtensionExpression.java b/exist-core/src/main/java/org/exist/xquery/ExtensionExpression.java index f97235c02fe..e18dcaf600e 100644 --- a/exist-core/src/main/java/org/exist/xquery/ExtensionExpression.java +++ b/exist-core/src/main/java/org/exist/xquery/ExtensionExpression.java @@ -33,24 +33,23 @@ * Implements an XQuery extension expression. An extension expression starts with * a list of pragmas, followed by an expression enclosed in curly braces. For evaluation * details check {{@link #eval(Sequence, Item)}. - * - * @author wolf * + * @author wolf */ public class ExtensionExpression extends AbstractExpression { private Expression innerExpression; - private List pragmas = new ArrayList<>(3); + private final List pragmas = new ArrayList<>(3); - public ExtensionExpression(XQueryContext context) { + public ExtensionExpression(final XQueryContext context) { super(context); } - public void setExpression(Expression inner) { + public void setExpression(final Expression inner) { this.innerExpression = inner; } - public void addPragma(Pragma pragma) { + public void addPragma(final Pragma pragma) { pragmas.add(pragma); } @@ -62,19 +61,20 @@ public void addPragma(Pragma pragma) { * will be thrown. If all pragmas return null, we call eval on the original expression and return * that. */ - public Sequence eval(Sequence contextSequence, Item contextItem) - throws XPathException { + @Override + public Sequence eval(final Sequence contextSequence, final Item contextItem) throws XPathException { callBefore(contextSequence); Sequence result = null; for (final Pragma pragma : pragmas) { - Sequence temp = pragma.eval(contextSequence, contextItem); + final Sequence temp = pragma.eval(contextSequence, contextItem); if (temp != null) { result = temp; break; } } - if (result == null) - {result = innerExpression.eval(contextSequence, contextItem);} + if (result == null) { + result = innerExpression.eval(contextSequence, contextItem); + } callAfter(); return result; } @@ -85,7 +85,7 @@ private void callAfter() throws XPathException { } } - private void callBefore(Sequence contextSequence) throws XPathException { + private void callBefore(final Sequence contextSequence) throws XPathException { for (final Pragma pragma : pragmas) { pragma.before(context, innerExpression, contextSequence); } @@ -95,7 +95,7 @@ public int returnsType() { return innerExpression.returnsType(); } - public void analyze(AnalyzeContextInfo contextInfo) throws XPathException { + public void analyze(final AnalyzeContextInfo contextInfo) throws XPathException { final AnalyzeContextInfo newContext = new AnalyzeContextInfo(contextInfo); for (final Pragma pragma : pragmas) { pragma.analyze(newContext); @@ -103,23 +103,19 @@ public void analyze(AnalyzeContextInfo contextInfo) throws XPathException { innerExpression.analyze(newContext); } - public void dump(ExpressionDumper dumper) { + public void dump(final ExpressionDumper dumper) { for (final Pragma pragma : pragmas) { - dumper.display("(# " + pragma.getQName().getStringValue(), line); - if (pragma.getContents() != null) - {dumper.display(' ').display(pragma.getContents());} - dumper.display("#)").nl(); + pragma.dump(dumper); + dumper.nl(); } dumper.display('{'); dumper.startIndent(); innerExpression.dump(dumper); dumper.endIndent(); - dumper.nl().display('}').nl(); + dumper.nl().display("}", line).nl(); } - /* (non-Javadoc) - * @see org.exist.xquery.AbstractExpression#getDependencies() - */ + @Override public int getDependencies() { return innerExpression.getDependencies(); } @@ -129,23 +125,24 @@ public Cardinality getCardinality() { return innerExpression.getCardinality(); } - public void setContextDocSet(DocumentSet contextSet) { + @Override + public void setContextDocSet(final DocumentSet contextSet) { super.setContextDocSet(contextSet); innerExpression.setContextDocSet(contextSet); } - public void setPrimaryAxis(int axis) { + @Override + public void setPrimaryAxis(final int axis) { innerExpression.setPrimaryAxis(axis); } + @Override public int getPrimaryAxis() { return innerExpression.getPrimaryAxis(); } - /* (non-Javadoc) - * @see org.exist.xquery.AbstractExpression#resetState() - */ - public void resetState(boolean postOptimization) { + @Override + public void resetState(final boolean postOptimization) { super.resetState(postOptimization); innerExpression.resetState(postOptimization); for (final Pragma pragma : pragmas) { @@ -153,7 +150,8 @@ public void resetState(boolean postOptimization) { } } - public void accept(ExpressionVisitor visitor) { + @Override + public void accept(final ExpressionVisitor visitor) { visitor.visit(innerExpression); } } diff --git a/exist-core/src/main/java/org/exist/xquery/Optimizer.java b/exist-core/src/main/java/org/exist/xquery/Optimizer.java index b26412d2e3f..28b38319bc6 100644 --- a/exist-core/src/main/java/org/exist/xquery/Optimizer.java +++ b/exist-core/src/main/java/org/exist/xquery/Optimizer.java @@ -21,15 +21,12 @@ */ package org.exist.xquery; -import org.exist.dom.QName; import org.exist.storage.DBBroker; import org.exist.xquery.functions.array.ArrayConstructor; import org.exist.xquery.pragmas.Optimize; import org.apache.logging.log4j.LogManager; import org.apache.logging.log4j.Logger; import org.exist.xquery.util.ExpressionDumper; -import org.exist.xquery.value.AtomicValue; -import org.exist.xquery.value.Type; import javax.annotation.Nullable; import java.util.*; @@ -82,7 +79,7 @@ public void visitLocationStep(final LocationStep locationStep) { // check query rewriters if they want to rewrite the location step Pragma optimizePragma = null; - for (QueryRewriter rewriter : rewriters) { + for (final QueryRewriter rewriter : rewriters) { try { optimizePragma = rewriter.rewriteLocationStep(locationStep); if (optimizePragma != null) { @@ -90,7 +87,7 @@ public void visitLocationStep(final LocationStep locationStep) { hasOptimized = true; break; } - } catch (XPathException e) { + } catch (final XPathException e) { LOG.warn("Exception called while rewriting location step: {}", e.getMessage(), e); } } diff --git a/exist-core/src/main/java/org/exist/xquery/Pragma.java b/exist-core/src/main/java/org/exist/xquery/Pragma.java index 6369f5383e5..4d881789779 100644 --- a/exist-core/src/main/java/org/exist/xquery/Pragma.java +++ b/exist-core/src/main/java/org/exist/xquery/Pragma.java @@ -22,57 +22,30 @@ package org.exist.xquery; import org.exist.dom.QName; +import org.exist.xquery.util.ExpressionDumper; import org.exist.xquery.value.Item; import org.exist.xquery.value.Sequence; -public abstract class Pragma { +import javax.annotation.Nullable; - private QName qname; - private String contents; - private Expression expression; - - public Pragma(QName qname, String contents) throws XPathException { - this(null, qname, contents); - } - - public Pragma(final Expression expression, QName qname, String contents) throws XPathException { - this.expression = expression; - this.qname = qname; - this.contents = contents; - } +/** + * Interface for implementing an XQuery Pragma expression. + * + * @author Adam Retter + */ +public interface Pragma { - public Expression getExpression() { - return expression; - } + QName getName(); - public void analyze(AnalyzeContextInfo contextInfo) throws XPathException { - } + void analyze(AnalyzeContextInfo contextInfo) throws XPathException; - public Sequence eval(Sequence contextSequence, Item contextItem) - throws XPathException { - return null; - } - - public abstract void before(XQueryContext context, Sequence contextSequence) throws XPathException; - - public abstract void before(XQueryContext context, final Expression expression, Sequence contextSequence) throws XPathException; - - public abstract void after(XQueryContext context) throws XPathException; - - public abstract void after(XQueryContext context, final Expression expression) throws XPathException; + void before(XQueryContext context, @Nullable Expression expression, Sequence contextSequence) throws XPathException; - protected String getContents() { - return contents; - } + Sequence eval(Sequence contextSequence, Item contextItem) throws XPathException; - protected QName getQName() { - return qname; - } + void after(XQueryContext context, @Nullable Expression expression) throws XPathException; - public void resetState(boolean postOptimization) { - } + void dump(final ExpressionDumper dumper); - public String toString() { - return "(# " + qname + ' ' + contents + "#)"; - } -} \ No newline at end of file + void resetState(boolean postOptimization); +} diff --git a/exist-core/src/main/java/org/exist/xquery/XQueryContext.java b/exist-core/src/main/java/org/exist/xquery/XQueryContext.java index 649ce3fe374..13d7e429c41 100644 --- a/exist-core/src/main/java/org/exist/xquery/XQueryContext.java +++ b/exist-core/src/main/java/org/exist/xquery/XQueryContext.java @@ -3076,7 +3076,7 @@ public Pragma getPragma(final String name, String contents) throws XPathExceptio } else if (Namespaces.EXIST_NS.equals(qname.getNamespaceURI())) { contents = StringValue.trimWhitespace(contents); - if (TimerPragma.TIMER_PRAGMA.equals(qname)) { + if (TimerPragma.TIMER_PRAGMA_NAME.equals(qname)) { return new TimerPragma(rootExpression, qname, contents); } diff --git a/exist-core/src/main/java/org/exist/xquery/pragmas/ForceIndexUse.java b/exist-core/src/main/java/org/exist/xquery/pragmas/ForceIndexUse.java index 721494cd986..2cf95802cd5 100644 --- a/exist-core/src/main/java/org/exist/xquery/pragmas/ForceIndexUse.java +++ b/exist-core/src/main/java/org/exist/xquery/pragmas/ForceIndexUse.java @@ -24,48 +24,35 @@ import org.exist.xquery.*; import org.exist.Namespaces; import org.exist.dom.QName; -import org.exist.xquery.value.Sequence; -public class ForceIndexUse extends Pragma { - - Expression expression; - boolean bailout = true; +public class ForceIndexUse extends AbstractPragma { - public static final QName EXCEPTION_IF_INDEX_NOT_USED_PRAGMA = - new QName("force-index-use", Namespaces.EXIST_NS, "exist"); + private boolean bailout = true; - public ForceIndexUse(QName qname, String contents) throws XPathException { - this(null, qname, contents); - } + public static final QName EXCEPTION_IF_INDEX_NOT_USED_PRAGMA = + new QName("force-index-use", Namespaces.EXIST_NS, "exist"); - public ForceIndexUse(final Expression expression, QName qname, String contents) throws XPathException { - super(expression, qname, contents); - } - - public void before(XQueryContext context,Sequence contextSequence) throws XPathException { - before(context, null, contextSequence); - } - - public void before(XQueryContext context, final Expression expression, Sequence contextSequence) throws XPathException { + public ForceIndexUse(final Expression expression, final QName qname, final String contents) { + super(expression, qname, contents); } - - public void after(XQueryContext context) throws XPathException { - after(context, null); - } - - public void after(XQueryContext context, final Expression expression) throws XPathException { - expression.accept(new DefaultExpressionVisitor() { - public void visitGeneralComparison(GeneralComparison expression) { - bailout = !expression.hasUsedIndex(); - } - public void visitBuiltinFunction(Function expression) { - if (expression instanceof IndexUseReporter) - {bailout = !((IndexUseReporter)expression).hasUsedIndex();} + + @Override + public void after(final XQueryContext context, final Expression expression) throws XPathException { + expression.accept(new DefaultExpressionVisitor() { + public void visitGeneralComparison(final GeneralComparison expression) { + bailout = !expression.hasUsedIndex(); } - }); - - if (bailout) - {throw new XPathException(expression, "XQDYxxxx: Can not use index on expression '" + expression + "'");} + + public void visitBuiltinFunction(final Function expression) { + if (expression instanceof IndexUseReporter) { + bailout = !((IndexUseReporter) expression).hasUsedIndex(); + } + } + }); + + if (bailout) { + throw new XPathException(expression, "XQDYxxxx: Can not use index on expression '" + expression + "'"); + } /* if (expression instanceof PathExpr) { diff --git a/exist-core/src/main/java/org/exist/xquery/pragmas/NoIndexPragma.java b/exist-core/src/main/java/org/exist/xquery/pragmas/NoIndexPragma.java index a12680e9d45..e34b4616595 100644 --- a/exist-core/src/main/java/org/exist/xquery/pragmas/NoIndexPragma.java +++ b/exist-core/src/main/java/org/exist/xquery/pragmas/NoIndexPragma.java @@ -26,45 +26,22 @@ import org.apache.logging.log4j.Logger; import org.exist.Namespaces; import org.exist.dom.QName; -import org.exist.xquery.value.Item; -import org.exist.xquery.value.Sequence; -public class NoIndexPragma extends Pragma { +public class NoIndexPragma extends AbstractPragma { - private final static Logger LOG = LogManager.getLogger(NoIndexPragma.class); + private static final Logger LOG = LogManager.getLogger(NoIndexPragma.class); - public final static QName NO_INDEX_PRAGMA = new QName("no-index", Namespaces.EXIST_NS, "exist"); + public static final QName NO_INDEX_PRAGMA = new QName("no-index", Namespaces.EXIST_NS, "exist"); - public NoIndexPragma(QName qname, String contents) throws XPathException { - this(null, qname, contents); - } - - public NoIndexPragma(final Expression expression, QName qname, String contents) throws XPathException { + public NoIndexPragma(final Expression expression, final QName qname, final String contents) { super(expression, qname, contents); } - public void analyze(AnalyzeContextInfo contextInfo) throws XPathException { + @Override + public void analyze(final AnalyzeContextInfo contextInfo) throws XPathException { if (LOG.isTraceEnabled()) { LOG.trace("Switching indexes off ..."); } contextInfo.addFlag(Expression.USE_TREE_TRAVERSAL); } - - public Sequence eval(Sequence contextSequence, Item contextItem) throws XPathException { - return null; - } - - public void before(XQueryContext context, Sequence contextSequence) throws XPathException { - before(context, null, contextSequence); - } - - public void before(XQueryContext context, final Expression expression, Sequence contextSequence) throws XPathException { - } - - public void after(XQueryContext context) throws XPathException { - after(context, null); - } - - public void after(XQueryContext context, final Expression expression) throws XPathException { - } } diff --git a/exist-core/src/main/java/org/exist/xquery/pragmas/Optimize.java b/exist-core/src/main/java/org/exist/xquery/pragmas/Optimize.java index 59f5e8751ca..a499c1e3b74 100644 --- a/exist-core/src/main/java/org/exist/xquery/pragmas/Optimize.java +++ b/exist-core/src/main/java/org/exist/xquery/pragmas/Optimize.java @@ -39,15 +39,14 @@ import java.util.Iterator; import java.util.List; -public class Optimize extends Pragma { +public class Optimize extends AbstractPragma { - public final static QName OPTIMIZE_PRAGMA = new QName("optimize", Namespaces.EXIST_NS, "exist"); + private static final Logger LOG = LogManager.getLogger(Optimize.class); + public static final QName OPTIMIZE_PRAGMA = new QName("optimize", Namespaces.EXIST_NS, "exist"); - private final static Logger LOG = LogManager.getLogger(Optimize.class); - - private boolean enabled = true; - private XQueryContext context; - private Optimizable optimizables[]; + private boolean enabled; + private final XQueryContext context; + private Optimizable[] optimizables; private Expression innerExpr = null; private LocationStep contextStep = null; private VariableReference contextVar = null; @@ -56,33 +55,33 @@ public class Optimize extends Pragma { private NodeSet cachedContext = null; private int cachedTimestamp; private boolean cachedOptimize; - - public Optimize(XQueryContext context, QName pragmaName, String contents, boolean explicit) throws XPathException { - this(null, context, pragmaName, contents, explicit); - } - - public Optimize(final Expression expression, XQueryContext context, QName pragmaName, String contents, boolean explicit) throws XPathException { + + public Optimize(final Expression expression, final XQueryContext context, final QName pragmaName, final String contents, final boolean explicit) throws XPathException { super(expression, pragmaName, contents); this.context = context; this.enabled = explicit || context.optimizationsEnabled(); - if (contents != null && contents.length() > 0) { - final String param[] = Option.parseKeyValuePair(contents); - if (param == null) - {throw new XPathException((Expression) null, "Invalid content found for pragma exist:optimize: " + contents);} + if (contents != null && !contents.isEmpty()) { + final String[] param = Option.parseKeyValuePair(contents); + if (param == null) { + throw new XPathException((Expression) null, "Invalid content found for pragma exist:optimize: " + contents); + } if ("enable".equals(param[0])) { enabled = "yes".equals(param[1]); } } } - public void analyze(AnalyzeContextInfo contextInfo) throws XPathException { + @Override + public void analyze(final AnalyzeContextInfo contextInfo) throws XPathException { super.analyze(contextInfo); this.contextId = contextInfo.getContextId(); } - public Sequence eval(Sequence contextSequence, Item contextItem) throws XPathException { - if (contextItem != null) - {contextSequence = contextItem.toSequence();} + @Override + public Sequence eval(Sequence contextSequence, final Item contextItem) throws XPathException { + if (contextItem != null) { + contextSequence = contextItem.toSequence(); + } boolean useCached = false; boolean optimize = false; @@ -91,18 +90,19 @@ public Sequence eval(Sequence contextSequence, Item contextItem) throws XPathExc if (contextSequence == null || contextSequence.isPersistentSet()) { // don't try to optimize in-memory node sets! // contextSequence will be overwritten originalContext = contextSequence == null ? null : contextSequence.toNodeSet(); - if (cachedContext != null && cachedContext == originalContext) - {useCached = !originalContext.hasChanged(cachedTimestamp);} + if (cachedContext != null && cachedContext == originalContext) { + useCached = !originalContext.hasChanged(cachedTimestamp); + } if (contextVar != null) { contextSequence = contextVar.eval(contextSequence); } // check if all Optimizable expressions signal that they can indeed optimize // in the current context - if (useCached) - {optimize = cachedOptimize;} - else { - if (optimizables != null && optimizables.length > 0) { - for (Optimizable optimizable : optimizables) { + if (useCached) { + optimize = cachedOptimize; + } else { + if (optimizables != null) { + for (final Optimizable optimizable : optimizables) { if (optimizable.canOptimize(contextSequence)) { optimize = true; } else { @@ -117,20 +117,20 @@ public Sequence eval(Sequence contextSequence, Item contextItem) throws XPathExc cachedContext = originalContext; cachedTimestamp = originalContext == null ? 0 : originalContext.getState(); cachedOptimize = true; - NodeSet ancestors; NodeSet result = null; for (int current = 0; current < optimizables.length; current++) { - NodeSet selection = optimizables[current].preSelect(contextSequence, current > 0); - if (LOG.isTraceEnabled()) - { - LOG.trace("exist:optimize: pre-selection: {}", selection.getLength());} + final NodeSet selection = optimizables[current].preSelect(contextSequence, current > 0); + if (LOG.isTraceEnabled()) { + LOG.trace("exist:optimize: pre-selection: {}", selection.getLength()); + } // determine the set of potential ancestors for which the predicate has to // be re-evaluated to filter out wrong matches - if (selection.isEmpty()) - {ancestors = selection;} - else if (contextStep == null || current > 0) { - ancestors = selection.selectAncestorDescendant(contextSequence.toNodeSet(), NodeSet.ANCESTOR, - true, contextId, true); + final NodeSet ancestors; + if (selection.isEmpty()) { + ancestors = selection; + } else if (contextStep == null || current > 0) { + ancestors = selection.selectAncestorDescendant(contextSequence.toNodeSet(), NodeSet.ANCESTOR, + true, contextId, true); } else { // NodeSelector selector; final long start = System.currentTimeMillis(); @@ -139,11 +139,11 @@ else if (contextStep == null || current > 0) { final QName ancestorQN = contextStep.getTest().getName(); if (optimizables[current].optimizeOnSelf()) { ancestors = index.findAncestorsByTagName(ancestorQN.getNameType(), ancestorQN, Constants.SELF_AXIS, - selection.getDocumentSet(), selection, contextId); + selection.getDocumentSet(), selection, contextId); } else { ancestors = index.findAncestorsByTagName(ancestorQN.getNameType(), ancestorQN, - optimizables[current].optimizeOnChild() ? Constants.PARENT_AXIS : Constants.ANCESTOR_SELF_AXIS, - selection.getDocumentSet(), selection, contextId); + optimizables[current].optimizeOnChild() ? Constants.PARENT_AXIS : Constants.ANCESTOR_SELF_AXIS, + selection.getDocumentSet(), selection, contextId); } if (LOG.isTraceEnabled()) { LOG.trace("Ancestor selection took {}", System.currentTimeMillis() - start); @@ -157,45 +157,47 @@ else if (contextStep == null || current > 0) { return innerExpr.eval(result); } else { contextStep.setPreloadedData(result.getDocumentSet(), result); - if (LOG.isTraceEnabled()) - { - LOG.trace("exist:optimize: context after optimize: {}", result.getLength());} + if (LOG.isTraceEnabled()) { + LOG.trace("exist:optimize: context after optimize: {}", result.getLength()); + } final long start = System.currentTimeMillis(); - if (originalContext != null) - {contextSequence = originalContext.filterDocuments(result);} - else - {contextSequence = null;} + if (originalContext != null) { + contextSequence = originalContext.filterDocuments(result); + } else { + contextSequence = null; + } final Sequence seq = innerExpr.eval(contextSequence); - if (LOG.isTraceEnabled()) - { - LOG.trace("exist:optimize: inner expr took {}; found: {}", System.currentTimeMillis() - start, seq.getItemCount());} + if (LOG.isTraceEnabled()) { + LOG.trace("exist:optimize: inner expr took {}; found: {}", System.currentTimeMillis() - start, seq.getItemCount()); + } return seq; } } else { - if (LOG.isTraceEnabled()) - {LOG.trace("exist:optimize: Cannot optimize expression.");} - if (originalContext != null) - {contextSequence = originalContext;} + if (LOG.isTraceEnabled()) { + LOG.trace("exist:optimize: Cannot optimize expression."); + } + if (originalContext != null) { + contextSequence = originalContext; + } return innerExpr.eval(contextSequence, contextItem); } } - public void before(XQueryContext context, Sequence contextSequence) throws XPathException { - before(context, null, contextSequence); - } - - public void before(XQueryContext context, Expression expression, Sequence contextSequence) throws XPathException { - if (innerExpr != null) - {return;} + @Override + public void before(final XQueryContext context, final Expression expression, final Sequence contextSequence) throws XPathException { + if (innerExpr != null) { + return; + } innerExpr = expression; - if (!enabled) - {return;} + if (!enabled) { + return; + } innerExpr.accept(new BasicExpressionVisitor() { - - public void visitPathExpr(PathExpr expression) { + @Override + public void visitPathExpr(final PathExpr expression) { for (int i = 0; i < expression.getLength(); i++) { final Expression next = expression.getExpression(i); - next.accept(this); + next.accept(this); } } @@ -209,10 +211,12 @@ public void visitLocationStep(final LocationStep locationStep) { } } - public void visitFilteredExpr(FilteredExpression filtered) { + @Override + public void visitFilteredExpr(final FilteredExpression filtered) { final Expression filteredExpr = filtered.getExpression(); - if (filteredExpr instanceof VariableReference) - {contextVar = (VariableReference) filteredExpr;} + if (filteredExpr instanceof VariableReference) { + contextVar = (VariableReference) filteredExpr; + } final List predicates = filtered.getPredicates(); for (final Predicate pred : predicates) { @@ -220,48 +224,47 @@ public void visitFilteredExpr(FilteredExpression filtered) { } } - public void visit(Expression expression) { + @Override + public void visit(final Expression expression) { super.visit(expression); } - public void visitGeneralComparison(GeneralComparison comparison) { - if (LOG.isTraceEnabled()) - { - LOG.trace("exist:optimize: found optimizable: {}", comparison.getClass().getName());} + @Override + public void visitGeneralComparison(final GeneralComparison comparison) { + if (LOG.isTraceEnabled()) { + LOG.trace("exist:optimize: found optimizable: {}", comparison.getClass().getName()); + } addOptimizable(comparison); } - public void visitPredicate(Predicate predicate) { + @Override + public void visitPredicate(final Predicate predicate) { predicate.getExpression(0).accept(this); } - public void visitBuiltinFunction(Function function) { + @Override + public void visitBuiltinFunction(final Function function) { if (function instanceof Optimizable) { - if (LOG.isTraceEnabled()) - { - LOG.trace("exist:optimize: found optimizable function: {}", function.getClass().getName());} + if (LOG.isTraceEnabled()) { + LOG.trace("exist:optimize: found optimizable function: {}", function.getClass().getName()); + } addOptimizable((Optimizable) function); } } }); contextStep = BasicExpressionVisitor.findFirstStep(innerExpr); - if (contextStep != null && contextStep.getTest().isWildcardTest()) - {contextStep = null;} + if (contextStep != null && contextStep.getTest().isWildcardTest()) { + contextStep = null; + } if (LOG.isTraceEnabled()) { LOG.trace("exist:optimize: context step: {}", contextStep); LOG.trace("exist:optimize: context var: {}", contextVar); } } - public void after(XQueryContext context) throws XPathException { - after(context, null); - } - - public void after(XQueryContext context, Expression expression) throws XPathException { - } - - private void addOptimizable(Optimizable optimizable) {final int axis = optimizable.getOptimizeAxis(); + private void addOptimizable(final Optimizable optimizable) { + final int axis = optimizable.getOptimizeAxis(); if (!(axis == Constants.CHILD_AXIS || axis == Constants.SELF_AXIS || axis == Constants.DESCENDANT_AXIS || axis == Constants.DESCENDANT_SELF_AXIS || axis == Constants.ATTRIBUTE_AXIS || axis == Constants.DESCENDANT_ATTRIBUTE_AXIS)) { @@ -272,14 +275,15 @@ public void after(XQueryContext context, Expression expression) throws XPathExce optimizables = new Optimizable[1]; optimizables[0] = optimizable; } else { - Optimizable o[] = new Optimizable[optimizables.length + 1]; + final Optimizable[] o = new Optimizable[optimizables.length + 1]; System.arraycopy(optimizables, 0, o, 0, optimizables.length); o[optimizables.length] = optimizable; optimizables = o; } } - public void resetState(boolean postOptimization) { + @Override + public void resetState(final boolean postOptimization) { super.resetState(postOptimization); cachedContext = null; } @@ -287,47 +291,51 @@ public void resetState(boolean postOptimization) { /** * Check every collection in the context sequence for an existing range index by QName. * - * @param context current context + * @param context current context * @param contextSequence context sequence - * @param qname QName indicating the index to check + * @param qname QName indicating the index to check * @return the type of a usable index or {@link org.exist.xquery.value.Type#ITEM} if there is no common - * index. + * index. */ - public static int getQNameIndexType(XQueryContext context, Sequence contextSequence, QName qname) { - if (contextSequence == null || qname == null) - {return Type.ITEM;} - - final String enforceIndexUse = - (String) context.getBroker().getConfiguration().getProperty(XQueryContext.PROPERTY_ENFORCE_INDEX_USE); + public static int getQNameIndexType(final XQueryContext context, final Sequence contextSequence, final QName qname) { + if (contextSequence == null || qname == null) { + return Type.ITEM; + } + + final String enforceIndexUse = + (String) context.getBroker().getConfiguration().getProperty(XQueryContext.PROPERTY_ENFORCE_INDEX_USE); int indexType = Type.ITEM; for (final Iterator i = contextSequence.getCollectionIterator(); i.hasNext(); ) { final Collection collection = i.next(); - if (collection.getURI().startsWith(XmldbURI.SYSTEM_COLLECTION_URI)) - {continue;} + if (collection.getURI().startsWith(XmldbURI.SYSTEM_COLLECTION_URI)) { + continue; + } final QNameRangeIndexSpec config = collection.getIndexByQNameConfiguration(context.getBroker(), qname); if (config == null) { // no index found for this collection - if (LOG.isTraceEnabled()) - { - LOG.trace("Cannot optimize: collection {} does not define an index on {}", collection.getURI(), qname);} + if (LOG.isTraceEnabled()) { + LOG.trace("Cannot optimize: collection {} does not define an index on {}", collection.getURI(), qname); + } // if enfoceIndexUse == "always", continue to check other collections // for indexes. It is sufficient if one collection defines an index - if (enforceIndexUse == null || !"always".equals(enforceIndexUse)) - {return Type.ITEM;} // found a collection without index + if (!"always".equals(enforceIndexUse)) { + return Type.ITEM; + } // found a collection without index } else { - int type = config.getType(); + final int type = config.getType(); if (indexType == Type.ITEM) { indexType = type; // if enforceIndexUse == "always", it is sufficient if one collection // defines an index. Just return it. - if (enforceIndexUse != null && "always".equals(enforceIndexUse)) - {return indexType;} + if ("always".equals(enforceIndexUse)) { + return indexType; + } } else if (indexType != type) { // found an index with a bad type. cannot optimize. // TODO: should this continue checking other collections? - if (LOG.isTraceEnabled()) - { - LOG.trace("Cannot optimize: collection {} does not define an index with the required type {} on {}", collection.getURI(), Type.getTypeName(type), qname);} + if (LOG.isTraceEnabled()) { + LOG.trace("Cannot optimize: collection {} does not define an index with the required type {} on {}", collection.getURI(), Type.getTypeName(type), qname); + } return Type.ITEM; // found a collection with a different type } } diff --git a/exist-core/src/main/java/org/exist/xquery/pragmas/ProfilePragma.java b/exist-core/src/main/java/org/exist/xquery/pragmas/ProfilePragma.java index 4c5ec49da0f..7e577dfc03a 100644 --- a/exist-core/src/main/java/org/exist/xquery/pragmas/ProfilePragma.java +++ b/exist-core/src/main/java/org/exist/xquery/pragmas/ProfilePragma.java @@ -26,34 +26,24 @@ import org.exist.dom.QName; import org.exist.xquery.value.Sequence; -public class ProfilePragma extends Pragma { +public class ProfilePragma extends AbstractPragma { - public final static QName PROFILING_PRAGMA = new QName("profiling", Namespaces.EXIST_NS, "exist"); + public static final QName PROFILING_PRAGMA = new QName("profiling", Namespaces.EXIST_NS, "exist"); - public ProfilePragma(QName qname, String contents) throws XPathException { - this(null, qname, contents); - } - - public ProfilePragma(final Expression expression, QName qname, String contents) throws XPathException { + public ProfilePragma(final Expression expression, final QName qname, final String contents) { super(expression, qname, contents); } - public void after(XQueryContext context) throws XPathException { - after(context, null); + @Override + public void before(final XQueryContext context, final Expression expression, final Sequence contextSequence) throws XPathException { + final Profiler profiler = context.getProfiler(); + final Option pragma = new Option(getExpression(), getName(), getContents()); + profiler.configure(pragma); } - public void after(XQueryContext context, Expression expression) throws XPathException { + @Override + public void after(final XQueryContext context, final Expression expression) throws XPathException { final Profiler profiler = context.getProfiler(); profiler.setEnabled(false); } - - public void before(XQueryContext context,Sequence contextSequence) throws XPathException { - before(context, null, contextSequence); - } - - public void before(XQueryContext context, Expression expression, Sequence contextSequence) throws XPathException { - final Profiler profiler = context.getProfiler(); - final Option pragma = new Option(getExpression(), getQName(), getContents()); - profiler.configure(pragma); - } } diff --git a/exist-core/src/main/java/org/exist/xquery/pragmas/TimerPragma.java b/exist-core/src/main/java/org/exist/xquery/pragmas/TimerPragma.java index ef32211fac3..a65ac715129 100644 --- a/exist-core/src/main/java/org/exist/xquery/pragmas/TimerPragma.java +++ b/exist-core/src/main/java/org/exist/xquery/pragmas/TimerPragma.java @@ -29,29 +29,26 @@ import org.exist.xquery.util.ExpressionDumper; import org.exist.xquery.value.Sequence; -public class TimerPragma extends Pragma { +public class TimerPragma extends AbstractPragma { + + public static final QName TIMER_PRAGMA_NAME = new QName("timer", Namespaces.EXIST_NS, "exist"); - public final static QName TIMER_PRAGMA = new QName("timer", Namespaces.EXIST_NS, "exist"); - private Logger log = null; - + private long start; private boolean verbose = true; - public TimerPragma(QName qname, String contents) throws XPathException { - this(null, qname, contents); - } - - public TimerPragma(final Expression expression, QName qname, String contents) throws XPathException { + public TimerPragma(final Expression expression, final QName qname, final String contents) throws XPathException { super(expression, qname, contents); - if (contents != null && contents.length() > 0) { - final String options[] = Option.tokenize(contents); - for (String option : options) { - final String param[] = Option.parseKeyValuePair(option); + if (contents != null && !contents.isEmpty()) { + + final String[] options = Option.tokenize(contents); + for (final String option : options) { + final String[] param = Option.parseKeyValuePair(option); if (param == null) { - throw new XPathException((Expression) null, "Invalid content found for pragma " + TIMER_PRAGMA.getStringValue() + - ": " + contents); + throw new XPathException((Expression) null, "Invalid content found for pragma " + TIMER_PRAGMA_NAME.getStringValue() + ": " + contents); } + if ("verbose".equals(param[0])) { verbose = "yes".equals(param[1]); } else if ("logger".equals(param[0])) { @@ -59,31 +56,25 @@ public TimerPragma(final Expression expression, QName qname, String contents) th } } } - if (log == null) - {log = LogManager.getLogger(TimerPragma.class);} + if (log == null) { + log = LogManager.getLogger(TimerPragma.class); + } } - public void after(XQueryContext context) throws XPathException { - after(context, null); + @Override + public void before(final XQueryContext context, final Expression expression, final Sequence contextSequence) throws XPathException { + this.start = System.currentTimeMillis(); } - public void after(XQueryContext context, Expression expression) throws XPathException { + @Override + public void after(final XQueryContext context, final Expression expression) throws XPathException { final long elapsed = System.currentTimeMillis() - start; if (log.isTraceEnabled()) { - if (verbose) - { - log.trace("Elapsed: {}ms. for expression:\n{}", elapsed, ExpressionDumper.dump(expression));} - else - { - log.trace("Elapsed: {}ms.", elapsed);} + if (verbose) { + log.trace("Elapsed: {}ms. for expression:\n{}", elapsed, ExpressionDumper.dump(expression)); + } else { + log.trace("Elapsed: {}ms.", elapsed); + } } } - - public void before(XQueryContext context, Sequence contextSequence) throws XPathException { - before(context, null, contextSequence); - } - - public void before(XQueryContext context, Expression expression, Sequence contextSequence) throws XPathException { - start = System.currentTimeMillis(); - } } diff --git a/extensions/indexes/range/src/main/java/org/exist/xquery/modules/range/OptimizeFieldPragma.java b/extensions/indexes/range/src/main/java/org/exist/xquery/modules/range/OptimizeFieldPragma.java index 1435470d3db..2bf981842a5 100644 --- a/extensions/indexes/range/src/main/java/org/exist/xquery/modules/range/OptimizeFieldPragma.java +++ b/extensions/indexes/range/src/main/java/org/exist/xquery/modules/range/OptimizeFieldPragma.java @@ -39,28 +39,28 @@ * * @author wolf */ -public class OptimizeFieldPragma extends Pragma { +public class OptimizeFieldPragma extends AbstractPragma { - public final static QName OPTIMIZE_RANGE_PRAGMA = new QName("optimize-field", Namespaces.EXIST_NS, "exist"); + public static final QName OPTIMIZE_RANGE_PRAGMA = new QName("optimize-field", Namespaces.EXIST_NS, "exist"); private final XQueryContext context; private Expression rewritten = null; private AnalyzeContextInfo contextInfo; private int axis; - public OptimizeFieldPragma(final Expression expression, QName qname, String contents, XQueryContext context) throws XPathException { + public OptimizeFieldPragma(final Expression expression, final QName qname, final String contents, final XQueryContext context) { super(expression, qname, contents); this.context = context; } @Override - public void analyze(AnalyzeContextInfo contextInfo) throws XPathException { + public void analyze(final AnalyzeContextInfo contextInfo) throws XPathException { super.analyze(contextInfo); this.contextInfo = contextInfo; } @Override - public Sequence eval(Sequence contextSequence, Item contextItem) throws XPathException { + public Sequence eval(final Sequence contextSequence, final Item contextItem) throws XPathException { if (rewritten != null) { rewritten.analyze(contextInfo); return rewritten.eval(contextSequence, contextItem); @@ -68,11 +68,6 @@ public Sequence eval(Sequence contextSequence, Item contextItem) throws XPathExc return null; } - @Override - public void before(final XQueryContext context, final Sequence contextSequence) throws XPathException { - before(context, null, contextSequence); - } - @Override public void before(final XQueryContext context, final Expression expression, final Sequence contextSequence) throws XPathException { final LocationStep locationStep = (LocationStep) expression; @@ -91,20 +86,11 @@ public void before(final XQueryContext context, final Expression expression, fin } } - public void after(XQueryContext context) throws XPathException { - after(context, null); - } - - @Override - public void after(XQueryContext context, Expression expression) throws XPathException { - - } - - private Expression tryRewriteToFields(LocationStep locationStep, final Predicate[] preds, NodePath contextPath, Sequence contextSequence) throws XPathException { + private @Nullable Expression tryRewriteToFields(final LocationStep locationStep, final Predicate[] preds, final NodePath contextPath, final Sequence contextSequence) throws XPathException { // without context path, we cannot rewrite the entire query if (contextPath != null) { final List notOptimizable = new ArrayList<>(preds.length); - List configs = getConfigurations(contextSequence); + final List configs = getConfigurations(contextSequence); // walk through the predicates attached to the current location step // check if expression can be optimized @@ -120,19 +106,19 @@ private Expression tryRewriteToFields(LocationStep locationStep, final Predicate notOptimizable.add(pred); continue; } - Expression innerExpr = pred.getExpression(0); - List steps = RangeQueryRewriter.getStepsToOptimize(innerExpr); + final Expression innerExpr = pred.getExpression(0); + final List steps = RangeQueryRewriter.getStepsToOptimize(innerExpr); if (steps == null) { notOptimizable.add(pred); continue; } // compute left hand path - NodePath innerPath = RangeQueryRewriter.toNodePath(steps); + final NodePath innerPath = RangeQueryRewriter.toNodePath(steps); if (innerPath == null) { notOptimizable.add(pred); continue; } - NodePath path = new NodePath(contextPath); + final NodePath path = new NodePath(contextPath); path.append(innerPath); if (path.length() > 0) { @@ -160,14 +146,14 @@ private Expression tryRewriteToFields(LocationStep locationStep, final Predicate final ArrayList matchedPreds = new ArrayList<>(); ComplexRangeIndexConfigElement rice = null; - for (ComplexRangeIndexConfigElement testRice : rices) { + for (final ComplexRangeIndexConfigElement testRice : rices) { if (testRice.getNumberOfConditions() > 0) { // find a config element where the conditions match preceding predicates matchedPreds.clear(); - for (Predicate precedingPred : precedingPreds ) { + for (final Predicate precedingPred : precedingPreds) { if (testRice.findCondition(precedingPred)) { matchedPreds.add(precedingPred); @@ -195,7 +181,7 @@ private Expression tryRewriteToFields(LocationStep locationStep, final Predicate if (rice != null && rice.getNodePath().match(contextPath)) { // check for a matching sub-path and retrieve field information - RangeIndexConfigField field = rice.getField(path); + final RangeIndexConfigField field = rice.getField(path); if (field != null) { if (args == null) { // initialize args @@ -235,7 +221,7 @@ private Expression tryRewriteToFields(LocationStep locationStep, final Predicate // the entire filter expression can be replaced // create range:field-equals function - FieldLookup func = new FieldLookup(context, FieldLookup.signatures[0]); + final FieldLookup func = new FieldLookup(context, FieldLookup.signatures[0]); func.setFallback(locationStep); func.setLocation(locationStep.getLine(), locationStep.getColumn()); @@ -259,7 +245,7 @@ private Expression tryRewriteToFields(LocationStep locationStep, final Predicate Expression optimizedExpr = new InternalFunctionCall(func); if (!notOptimizable.isEmpty()) { final FilteredExpression filtered = new FilteredExpression(context, optimizedExpr); - for (Predicate pred : notOptimizable) { + for (final Predicate pred : notOptimizable) { filtered.addPredicate(pred); } optimizedExpr = filtered; @@ -271,12 +257,12 @@ private Expression tryRewriteToFields(LocationStep locationStep, final Predicate return null; } - private Expression getKeyArg(Expression expression) { + private @Nullable Expression getKeyArg(final Expression expression) { if (expression instanceof GeneralComparison) { - return ((GeneralComparison)expression).getRight(); + return ((GeneralComparison) expression).getRight(); } else if (expression instanceof InternalFunctionCall) { - InternalFunctionCall fcall = (InternalFunctionCall) expression; - Function function = fcall.getFunction(); + final InternalFunctionCall fcall = (InternalFunctionCall) expression; + final Function function = fcall.getFunction(); if (function instanceof Lookup) { return function.getArgument(1); } @@ -284,31 +270,28 @@ private Expression getKeyArg(Expression expression) { return null; } - /** * Find all complex configurations matching the path */ - private List findConfigurations(NodePath path, List configs) { - ArrayList rices = new ArrayList<>(); - - for (RangeIndexConfig config : configs) { - List foundRices = config.findAll(path); + private List findConfigurations(final NodePath path, final List configs) { + final List rices = new ArrayList<>(); + for (final RangeIndexConfig config : configs) { + final List foundRices = config.findAll(path); if (rices.addAll(foundRices)) { break; } } - return rices; } - private List getConfigurations(Sequence contextSequence) { - List configs = new ArrayList<>(); + private List getConfigurations(final Sequence contextSequence) { + final List configs = new ArrayList<>(); for (final Iterator i = contextSequence.getCollectionIterator(); i.hasNext(); ) { final Collection collection = i.next(); if (collection.getURI().startsWith(XmldbURI.SYSTEM_COLLECTION_URI)) { continue; } - IndexSpec idxConf = collection.getIndexConfiguration(context.getBroker()); + final IndexSpec idxConf = collection.getIndexConfiguration(context.getBroker()); if (idxConf != null) { final RangeIndexConfig config = (RangeIndexConfig) idxConf.getCustomIndexSpec(RangeIndex.ID); if (config != null) { From bd704b328f3aba382cbf733e25427db1bc0ba4bb Mon Sep 17 00:00:00 2001 From: Adam Retter Date: Wed, 4 Oct 2023 15:51:37 +0100 Subject: [PATCH 2/3] [refactor] Renamed 'exist:timer' pragma to 'exist:time' to better reflect its purpose. Leaves 'exist:timer' as an intact legacy supported name for now too --- .../main/java/org/exist/xquery/XQueryContext.java | 4 ++-- .../pragmas/{TimerPragma.java => TimePragma.java} | 15 ++++++++++----- 2 files changed, 12 insertions(+), 7 deletions(-) rename exist-core/src/main/java/org/exist/xquery/pragmas/{TimerPragma.java => TimePragma.java} (81%) diff --git a/exist-core/src/main/java/org/exist/xquery/XQueryContext.java b/exist-core/src/main/java/org/exist/xquery/XQueryContext.java index 13d7e429c41..e1c397daa46 100644 --- a/exist-core/src/main/java/org/exist/xquery/XQueryContext.java +++ b/exist-core/src/main/java/org/exist/xquery/XQueryContext.java @@ -3076,8 +3076,8 @@ public Pragma getPragma(final String name, String contents) throws XPathExceptio } else if (Namespaces.EXIST_NS.equals(qname.getNamespaceURI())) { contents = StringValue.trimWhitespace(contents); - if (TimerPragma.TIMER_PRAGMA_NAME.equals(qname)) { - return new TimerPragma(rootExpression, qname, contents); + if (TimePragma.TIME_PRAGMA_NAME.equals(qname) || TimePragma.DEPRECATED_TIMER_PRAGMA_NAME.equals(qname)) { + return new TimePragma(rootExpression, qname, contents); } if (Optimize.OPTIMIZE_PRAGMA.equals(qname)) { diff --git a/exist-core/src/main/java/org/exist/xquery/pragmas/TimerPragma.java b/exist-core/src/main/java/org/exist/xquery/pragmas/TimePragma.java similarity index 81% rename from exist-core/src/main/java/org/exist/xquery/pragmas/TimerPragma.java rename to exist-core/src/main/java/org/exist/xquery/pragmas/TimePragma.java index a65ac715129..302e8f136c4 100644 --- a/exist-core/src/main/java/org/exist/xquery/pragmas/TimerPragma.java +++ b/exist-core/src/main/java/org/exist/xquery/pragmas/TimePragma.java @@ -29,16 +29,21 @@ import org.exist.xquery.util.ExpressionDumper; import org.exist.xquery.value.Sequence; -public class TimerPragma extends AbstractPragma { +/** + * An XQuery Pragma that will record the execution + * time of the associated expression. + */ +public class TimePragma extends AbstractPragma { - public static final QName TIMER_PRAGMA_NAME = new QName("timer", Namespaces.EXIST_NS, "exist"); + public static final QName TIME_PRAGMA_NAME = new QName("time", Namespaces.EXIST_NS, "exist"); + public static final QName DEPRECATED_TIMER_PRAGMA_NAME = new QName("timer", Namespaces.EXIST_NS, "exist"); private Logger log = null; private long start; private boolean verbose = true; - public TimerPragma(final Expression expression, final QName qname, final String contents) throws XPathException { + public TimePragma(final Expression expression, final QName qname, final String contents) throws XPathException { super(expression, qname, contents); if (contents != null && !contents.isEmpty()) { @@ -46,7 +51,7 @@ public TimerPragma(final Expression expression, final QName qname, final String for (final String option : options) { final String[] param = Option.parseKeyValuePair(option); if (param == null) { - throw new XPathException((Expression) null, "Invalid content found for pragma " + TIMER_PRAGMA_NAME.getStringValue() + ": " + contents); + throw new XPathException((Expression) null, "Invalid content found for pragma " + TIME_PRAGMA_NAME.getStringValue() + ": " + contents); } if ("verbose".equals(param[0])) { @@ -57,7 +62,7 @@ public TimerPragma(final Expression expression, final QName qname, final String } } if (log == null) { - log = LogManager.getLogger(TimerPragma.class); + log = LogManager.getLogger(TimePragma.class); } } From bd13f5922ee031be5e3ea5dcf3e53e73e94cfe01 Mon Sep 17 00:00:00 2001 From: Adam Retter Date: Wed, 4 Oct 2023 17:09:01 +0100 Subject: [PATCH 3/3] [feature] A new and improved 'exist:time' XQuery pragma. Backported from FusionDB --- exist-core/pom.xml | 2 + .../main/java/org/exist/xquery/Option.java | 6 +- .../org/exist/xquery/pragmas/TimePragma.java | 511 +++++++++++++++++- 3 files changed, 487 insertions(+), 32 deletions(-) diff --git a/exist-core/pom.xml b/exist-core/pom.xml index ed5243c2c33..96cbbc310cf 100644 --- a/exist-core/pom.xml +++ b/exist-core/pom.xml @@ -712,6 +712,7 @@ src/test/java/org/exist/xquery/functions/session/AttributeTest.java src/test/java/org/exist/xquery/functions/xmldb/XMLDBAuthenticateTest.java src/main/java/org/exist/xquery/functions/util/Eval.java + src/main/java/org/exist/xquery/pragmas/TimePragma.java src/test/java/org/exist/xquery/util/URIUtilsTest.java src/main/java/org/exist/xquery/value/ArrayListValueSequence.java src/test/java/org/exist/xquery/value/BifurcanMapTest.java @@ -862,6 +863,7 @@ The original license statement is also included below.]]> src/test/java/org/exist/xquery/functions/session/AttributeTest.java src/test/java/org/exist/xquery/functions/xmldb/XMLDBAuthenticateTest.java src/main/java/org/exist/xquery/functions/util/Eval.java + src/main/java/org/exist/xquery/pragmas/TimePragma.java src/test/java/org/exist/xquery/util/URIUtilsTest.java src/main/java/org/exist/xquery/value/ArrayListValueSequence.java src/test/java/org/exist/xquery/value/BifurcanMapTest.java diff --git a/exist-core/src/main/java/org/exist/xquery/Option.java b/exist-core/src/main/java/org/exist/xquery/Option.java index 72b7d86b385..27f8615dfdb 100644 --- a/exist-core/src/main/java/org/exist/xquery/Option.java +++ b/exist-core/src/main/java/org/exist/xquery/Option.java @@ -28,6 +28,8 @@ import org.exist.Namespaces; import org.exist.dom.QName; +import javax.annotation.Nullable; + /** * Represents an XQuery option declared via "declare option". * @@ -89,9 +91,9 @@ public static String[] tokenize(final String contents) { return items; } - public static String[] parseKeyValuePair(final String s) { + public static @Nullable String[] parseKeyValuePair(final String s) { final Matcher matcher = pattern.matcher(s); - if(matcher.matches()) { + if (matcher.matches()) { String value = matcher.group(2); if(value.charAt(0) == '\'' || value.charAt(0) == '"') { value = value.substring(1, value.length() - 1); diff --git a/exist-core/src/main/java/org/exist/xquery/pragmas/TimePragma.java b/exist-core/src/main/java/org/exist/xquery/pragmas/TimePragma.java index 302e8f136c4..5a9d29a8ee2 100644 --- a/exist-core/src/main/java/org/exist/xquery/pragmas/TimePragma.java +++ b/exist-core/src/main/java/org/exist/xquery/pragmas/TimePragma.java @@ -1,14 +1,25 @@ /* - * eXist-db Open Source Native XML Database - * Copyright (C) 2001 The eXist-db Authors + * Copyright (C) 2014, Evolved Binary Ltd * - * info@exist-db.org - * http://www.exist-db.org + * This file was originally ported from FusionDB to eXist-db by + * Evolved Binary, for the benefit of the eXist-db Open Source community. + * Only the ported code as it appears in this file, at the time that + * it was contributed to eXist-db, was re-licensed under The GNU + * Lesser General Public License v2.1 only for use in eXist-db. + * + * This license grant applies only to a snapshot of the code as it + * appeared when ported, it does not offer or infer any rights to either + * updates of this source code or access to the original source code. + * + * The GNU Lesser General Public License v2.1 only license follows. + * + * --------------------------------------------------------------------- + * + * Copyright (C) 2014, Evolved Binary Ltd * * This library is free software; you can redistribute it and/or * modify it under the terms of the GNU Lesser General Public - * License as published by the Free Software Foundation; either - * version 2.1 of the License, or (at your option) any later version. + * License as published by the Free Software Foundation; version 2.1. * * This library is distributed in the hope that it will be useful, * but WITHOUT ANY WARRANTY; without even the implied warranty of @@ -21,6 +32,8 @@ */ package org.exist.xquery.pragmas; +import com.evolvedbinary.j8fu.tuple.Tuple2; +import org.apache.logging.log4j.Level; import org.exist.xquery.*; import org.apache.logging.log4j.LogManager; import org.apache.logging.log4j.Logger; @@ -29,57 +42,495 @@ import org.exist.xquery.util.ExpressionDumper; import org.exist.xquery.value.Sequence; +import javax.annotation.Nullable; +import java.util.Optional; + +import static com.evolvedbinary.j8fu.tuple.Tuple.Tuple; + /** * An XQuery Pragma that will record the execution - * time of the associated expression. + * time of the associated expression via logging. + * + * 
{@code
+ * (# exist:time verbose=yes logger-name=MyLog logging-level=TRACE log-message-prefix=LOOK-HERE #) {
+ *     (: the XQuery Expression that you wish to time goes here :)
+ * }
+ * }
+ * + * The following optional configuration options may be given to the Time Pragma via the pragma's contents: + * * verbose - Set to 'true' if you want the associated expression to be logged to. You may also use 'yes' instead of 'true' but its use is deprecated and may be removed in the future. + * * logger-name - The name of the logger to use, if omitted the logger for {@link TimePragma} will be used. + * * logging-level - The Slf4j level at which the timing should be logged, e.g. Trace, Debug, Info, Warn, Error, etc. If omitted this defaults to 'Trace' level. + * * log-message-prefix - An optional prefix to append to the start of the log message to help you identify it. + * * measurement-mode - indicates whether we should measure a single invocation of the additional expression or multiple invocations 'single' or 'multiple'. The default is 'single'. + * + * @author Adam Retter */ public class TimePragma extends AbstractPragma { public static final QName TIME_PRAGMA_NAME = new QName("time", Namespaces.EXIST_NS, "exist"); public static final QName DEPRECATED_TIMER_PRAGMA_NAME = new QName("timer", Namespaces.EXIST_NS, "exist"); - private Logger log = null; - - private long start; - private boolean verbose = true; + private final Options options; + @Nullable private Timing timing = null; public TimePragma(final Expression expression, final QName qname, final String contents) throws XPathException { super(expression, qname, contents); - if (contents != null && !contents.isEmpty()) { + this.options = parseOptions(getContents()); + } + + @Override + public void before(final XQueryContext context, final Expression expression, final Sequence contextSequence) throws XPathException { + if (timing == null) { + this.timing = new Timing(); + } + timing.setStartTimestamp(System.nanoTime()); + } + + @Override + public void after(final XQueryContext context, final Expression expression) throws XPathException { + timing.setEndTimestamp(System.nanoTime()); + + if (options.measurementMode == MeasurementMode.SINGLE) { + logSingleMeasurement(expression); + this.timing.reset(); + } + } + + @Override + public void resetState(final boolean postOptimization) { + if (timing != null && options.measurementMode == MeasurementMode.MULTIPLE) { + logMultipleMeasurement(); + } + this.timing.reset(); + } + + /** + * Return the nanoseconds as either + * nanoseconds or milliseconds. + * + * @param nanoseconds the time in milliseconds. + * + * @return the time. + */ + private static Tuple2 nsOrMs(final long nanoseconds) { + final long timeValue; + final String timeUnit; + if (nanoseconds > 999_999) { + timeValue = nanoseconds / 1_000_000; + timeUnit = "ms"; + } else { + timeValue = nanoseconds; + timeUnit = "ns"; + } + return Tuple(timeValue, timeUnit); + } + + /** + * Return the nanoseconds as either + * nanoseconds or milliseconds. + * + * @param nanoseconds the time in milliseconds. + * + * @return the time. + */ + private static String nsOrMsStr(final long nanoseconds) { + final Tuple2 time = nsOrMs(nanoseconds); + return String.format("%d %s", time._1, time._2); + } + + /** + * Return the nanoseconds as either + * nanoseconds or milliseconds. + * + * @param nanoseconds the time in milliseconds. + * + * @return the time. + */ + private static Tuple2 nsOrMsDbl(final double nanoseconds) { + final double timeValue; + final String timeUnit; + if (nanoseconds > 999_999) { + timeValue = nanoseconds / 1_000_000; + timeUnit = "ms"; + } else { + timeValue = nanoseconds; + timeUnit = "ns"; + } + return Tuple(timeValue, timeUnit); + } + + /** + * Return the nanoseconds as either + * nanoseconds or milliseconds. + * + * @param nanoseconds the time in milliseconds. + * + * @return the time. + */ + private static String nsOrMsStrDbl(final double nanoseconds) { + final Tuple2 time = nsOrMsDbl(nanoseconds); + return String.format("%.2f %s", time._1, time._2); + } + + private void logSingleMeasurement(final Expression expression) { + final long elapsedTime = timing.getTotalElapsed(); + @Nullable final String humaneElapsedTime = elapsedTime > (1_000_000 * 999) ? formatHumaneElapsedTime(elapsedTime) : null; + + final String displayTime = nsOrMsStr(elapsedTime); + + if (options.logger.isEnabled(options.loggingLevel)) { + + if (options.logMessagePrefix != null) { + if (options.verbose) { + if (humaneElapsedTime != null) { + options.logger.log(options.loggingLevel, "{} Elapsed: {} ({}) for expression: {}", options.logMessagePrefix, displayTime, humaneElapsedTime, ExpressionDumper.dump(expression)); + } else { + options.logger.log(options.loggingLevel, "{} Elapsed: {} for expression: {}", options.logMessagePrefix, displayTime, ExpressionDumper.dump(expression)); + } + } else { + if (humaneElapsedTime != null) { + options.logger.log(options.loggingLevel, "{} Elapsed: {} ({}).", options.logMessagePrefix, displayTime, humaneElapsedTime); + } else { + options.logger.log(options.loggingLevel, "{} Elapsed: {}.", options.logMessagePrefix, displayTime); + } + } + } else { + if (options.verbose) { + if (humaneElapsedTime != null) { + options.logger.log(options.loggingLevel, "Elapsed: {} ({}) for expression: {}", displayTime, humaneElapsedTime, ExpressionDumper.dump(expression)); + } else { + options.logger.log(options.loggingLevel, "Elapsed: {} for expression: {}", displayTime, ExpressionDumper.dump(expression)); + } + } else { + if (humaneElapsedTime != null) { + options.logger.log(options.loggingLevel, "Elapsed: {} ({}).", displayTime, humaneElapsedTime); + } else { + options.logger.log(options.loggingLevel, "Elapsed: {}.", displayTime); + } + } + } + } + } + + private void logMultipleMeasurement() { + final long elapsedTime = timing.getTotalElapsed(); + @Nullable final String humaneElapsedTime = elapsedTime > 999 ? formatHumaneElapsedTime(elapsedTime) : null; + + final String displayTime = nsOrMsStr(elapsedTime); + + if (options.logMessagePrefix != null) { + if (humaneElapsedTime != null) { + options.logger.log(options.loggingLevel, "{} Elapsed: {} ({}) [iterations={} first={}, min={}, avg={}, max={}, last={}].", options.logMessagePrefix, displayTime, humaneElapsedTime, timing.getIterations(), nsOrMsStr(timing.getFirstElapsed()), nsOrMsStr(timing.getMinElapsed()), nsOrMsStrDbl(timing.getAvgElapsed()), nsOrMsStr(timing.getMaxElapsed()), nsOrMsStr(timing.getLastElapsed())); + } else { + options.logger.log(options.loggingLevel, "{} Elapsed: {} [iterations={} first={}, min={}, avg={}, max={}, last={}].", options.logMessagePrefix, displayTime, timing.getIterations(), nsOrMsStr(timing.getFirstElapsed()), nsOrMsStr(timing.getMinElapsed()), nsOrMsStrDbl(timing.getAvgElapsed()), nsOrMsStr(timing.getMaxElapsed()), nsOrMsStr(timing.getLastElapsed())); + } + } else { + if (humaneElapsedTime != null) { + options.logger.log(options.loggingLevel, "Elapsed: {} ({}) [iterations={} first={}, min={}, avg={}, max={}, last={}].", displayTime, humaneElapsedTime, timing.getIterations(), nsOrMsStr(timing.getFirstElapsed()), nsOrMsStr(timing.getMinElapsed()), nsOrMsStrDbl(timing.getAvgElapsed()), nsOrMsStr(timing.getMaxElapsed()), nsOrMsStr(timing.getLastElapsed())); + } else { + options.logger.log(options.loggingLevel, "Elapsed: {} [iterations={} first={}, min={}, avg={}, max={}, last={}].", displayTime, timing.getIterations(), nsOrMsStr(timing.getFirstElapsed()), nsOrMsStr(timing.getMinElapsed()), nsOrMsStrDbl(timing.getAvgElapsed()), nsOrMsStr(timing.getMaxElapsed()), nsOrMsStr(timing.getLastElapsed())); + } + } + } + + /** + * Format the elapsed time in a humane manner. + * + * @param elapsedTime the elapsed time in nanoseconds. + * + * @return a string of the duration which is suitable for consumptions by humans. + */ + private static String formatHumaneElapsedTime(final long elapsedTime) { + final long nanoseconds = elapsedTime % 1_000_000; + + final double ms = elapsedTime / 1_000_000; + final long milliseconds = (long)(ms % 1_000); + + final double s = ms / 1_000; + final long seconds = (long)(s % 60); + + final double m = s / 60; + final long minutes = (long)(m % 60); + + final double h = m / 60; + final long hours = (long)(h % 60); + + final StringBuilder humane = new StringBuilder(); + + if (hours > 0) { + humane.append(hours).append(" hour"); + if (hours > 1) { + humane.append('s'); + } + } + + if (minutes > 0) { + if (humane.length() > 0) { + humane.append(", "); + if (seconds == 0 && milliseconds == 0 && nanoseconds == 0) { + humane.append("and "); + } + } + humane.append(minutes).append(" minute"); + if (minutes > 1) { + humane.append('s'); + } + } + + if (seconds > 0) { + if (humane.length() > 0) { + humane.append(", "); + if (milliseconds == 0 && nanoseconds == 0) { + humane.append("and "); + } + } + + humane.append(seconds).append(" second"); + if (seconds > 1) { + humane.append('s'); + } + } + + if (milliseconds > 0) { + if (humane.length() > 0) { + humane.append(", "); + if (nanoseconds == 0) { + humane.append("and "); + } + } + + humane.append(milliseconds).append(" ms"); + } + + if (nanoseconds > 0) { + if (humane.length() > 0) { + humane.append(", and "); + } + + humane.append(nanoseconds).append(" ns"); + } + + return humane.toString(); + } + + /** + * Extract any options for the TimePragma from the Pragma Contents. + * + * @param contents the pragma contents. + * + * @return the options. + */ + private static Options parseOptions(@Nullable final String contents) throws XPathException { + boolean verbose = false; + @Nullable String loggerName = null; + @Nullable String loggingLevelName = null; + @Nullable String logMessagePrefix = null; + @Nullable String measurementModeStr = null; + + if (contents != null && !contents.isEmpty()) { final String[] options = Option.tokenize(contents); for (final String option : options) { - final String[] param = Option.parseKeyValuePair(option); + @Nullable final String[] param = Option.parseKeyValuePair(option); if (param == null) { throw new XPathException((Expression) null, "Invalid content found for pragma " + TIME_PRAGMA_NAME.getStringValue() + ": " + contents); } - if ("verbose".equals(param[0])) { - verbose = "yes".equals(param[1]); - } else if ("logger".equals(param[0])) { - log = LogManager.getLogger(param[1]); + switch (param[0]) { + case "verbose": + verbose = "true".equals(param[1]) || "yes".equals(param[1]); + break; + + case "logger-name": + loggerName = param[1]; + break; + + case "logging-level": + loggingLevelName = param[1]; + break; + + case "log-message-prefix": + logMessagePrefix = param[1]; + break; + + case "measurement-mode": + measurementModeStr = param[1]; + break; } } } - if (log == null) { - log = LogManager.getLogger(TimePragma.class); + + final Logger logger = Optional.ofNullable(loggerName).flatMap(s -> Optional.ofNullable(LogManager.getLogger(s))).orElseGet(() -> LogManager.getLogger(TimePragma.class)); + final Level loggingLevel = Optional.ofNullable(loggingLevelName).flatMap(s -> Optional.ofNullable(Level.getLevel(s))).orElse(Level.TRACE); + final MeasurementMode measurementMode = Optional.ofNullable(measurementModeStr).map(String::toUpperCase).map(s -> { + try { + return MeasurementMode.valueOf(s); + } catch (final IllegalArgumentException e) { + return MeasurementMode.SINGLE; + } + }).orElse(MeasurementMode.SINGLE); + + return new Options(verbose, logger, loggingLevel, logMessagePrefix, measurementMode); + } + + /** + * Holds the options for the Timer Pragma. + */ + private static class Options { + final boolean verbose; + final Logger logger; + final Level loggingLevel; + @Nullable final String logMessagePrefix; + final MeasurementMode measurementMode; + + private Options(final boolean verbose, final Logger logger, final Level loggingLevel, @Nullable final String logMessagePrefix, final MeasurementMode measurementMode) { + this.verbose = verbose; + this.logger = logger; + this.loggingLevel = loggingLevel; + this.logMessagePrefix = logMessagePrefix; + this.measurementMode = measurementMode; } } - @Override - public void before(final XQueryContext context, final Expression expression, final Sequence contextSequence) throws XPathException { - this.start = System.currentTimeMillis(); + /** + * The mode of measurement. + */ + private enum MeasurementMode { + SINGLE, + MULTIPLE } - @Override - public void after(final XQueryContext context, final Expression expression) throws XPathException { - final long elapsed = System.currentTimeMillis() - start; - if (log.isTraceEnabled()) { - if (verbose) { - log.trace("Elapsed: {}ms. for expression:\n{}", elapsed, ExpressionDumper.dump(expression)); - } else { - log.trace("Elapsed: {}ms.", elapsed); + /** + * Holds the timings for multiple iterations of the Pragma's additional expression. + */ + private static class Timing { + private static final int UNSET = -1; + + private long startTimestamp = UNSET; + + private long lastStartTimestamp = UNSET; + + private long firstElapsed = UNSET; + private long minElapsed = UNSET; + private long maxElapsed = UNSET; + private long lastElapsed = UNSET; + private long totalElapsed = 0; + + private int iterations = 0; + + /** + * Set the start timestamp of an iteration. + * + * @param startTimestamp the starting timestamp of an iteration. + */ + public void setStartTimestamp(final long startTimestamp) { + if (this.startTimestamp == UNSET) { + this.startTimestamp = startTimestamp; } + this.lastStartTimestamp = startTimestamp; + } + + /** + * Set the end timestamp of an iteration. + * + * @param endTimestamp the end timestamp of an iteration. + */ + public void setEndTimestamp(final long endTimestamp) { + this.iterations++; + + final long elapsed = endTimestamp - lastStartTimestamp; + if (firstElapsed == UNSET) { + this.firstElapsed = elapsed; + } + if (minElapsed == UNSET || elapsed < minElapsed) { + minElapsed = elapsed; + } + if (elapsed > maxElapsed) { + maxElapsed = elapsed; + } + this.lastElapsed = elapsed; + this.totalElapsed += elapsed; + } + + /** + * Get the number of iterations that have been recorded. + * + * @return the number of iterations + */ + public int getIterations() { + return iterations; + } + + /** + * Get the elapsed time of the first iteration. + * + * @return the elapsed time of the first iteration. + */ + public long getFirstElapsed() { + return firstElapsed; + } + + /** + * Get the elapsed time of the shortest iteration, i.e. the least time spent on an iteration. + * + * @return the elapsed time of the shortest iteration. + */ + public long getMinElapsed() { + return minElapsed; + } + + /** + * Get the average elapsed time of all iterations. + * + * @return the average elapsed time of all iterations. + */ + public double getAvgElapsed() { + return getTotalElapsed() / (double) iterations; + } + + /** + * Get the elapsed time of the longest iteration, i.e. the most time spent on an iteration. + * + * @return the elapsed time of the longest iteration. + */ + public long getMaxElapsed() { + return maxElapsed; + } + + /** + * Get the elapsed time of the last iteration. + * + * @return the elapsed time of the last iteration. + */ + public long getLastElapsed() { + return lastElapsed; + } + + /** + * Get the total elapsed time of all iterations. + * + * @return the total elapsed time of all iterations. + */ + public long getTotalElapsed() { + return totalElapsed; + } + + /** + * Reset the class for next use. + */ + public void reset() { + this.startTimestamp = UNSET; + + this.lastStartTimestamp = UNSET; + + this.firstElapsed = UNSET; + this.minElapsed = UNSET; + this.maxElapsed = UNSET; + this.lastElapsed = UNSET; + this.totalElapsed = 0; + + this.iterations = 0; } } }