From b672cf2cdfd5d90cdd7ce4c83b62654e8d9ea877 Mon Sep 17 00:00:00 2001 From: Barry Nouwt Date: Thu, 1 May 2025 22:59:48 +0200 Subject: [PATCH 1/2] Performance and logging improvements. Make sure trace log level allows us to notice long translating and merging times. The hashcode of the TripleNode was wrong (from the start) and this caused considerable performance bottleneck. It is now corrected. --- .../java/eu/knowledge/engine/reasoner/api/TripleNode.java | 2 +- .../eu/knowledge/engine/reasoner/api/TriplePattern.java | 2 +- .../engine/reasoner/api/TripleVarBindingSet.java | 8 ++++++++ 3 files changed, 10 insertions(+), 2 deletions(-) diff --git a/reasoner/src/main/java/eu/knowledge/engine/reasoner/api/TripleNode.java b/reasoner/src/main/java/eu/knowledge/engine/reasoner/api/TripleNode.java index 67e62d9f3..b2e0c6586 100644 --- a/reasoner/src/main/java/eu/knowledge/engine/reasoner/api/TripleNode.java +++ b/reasoner/src/main/java/eu/knowledge/engine/reasoner/api/TripleNode.java @@ -18,10 +18,10 @@ public class TripleNode { public TripleNode(TriplePattern aTriplePattern, Node aNode, int aNodeIdx) { assert (0 <= aNodeIdx && aNodeIdx <= 2); - this.hashCodeValue = this.calcHashCode(); this.tp = aTriplePattern; this.node = aNode; this.nodeIdx = aNodeIdx; + this.hashCodeValue = this.calcHashCode(); } public TripleNode(TriplePattern aTriplePattern, String aNode, int aNodeIdx) { diff --git a/reasoner/src/main/java/eu/knowledge/engine/reasoner/api/TriplePattern.java b/reasoner/src/main/java/eu/knowledge/engine/reasoner/api/TriplePattern.java index ee66c117b..edbe9bf65 100644 --- a/reasoner/src/main/java/eu/knowledge/engine/reasoner/api/TriplePattern.java +++ b/reasoner/src/main/java/eu/knowledge/engine/reasoner/api/TriplePattern.java @@ -64,7 +64,7 @@ public Node getObject() { * @return */ public Map findMatches(TriplePattern other) { - Map substitutionMap = new HashMap<>(); + Map substitutionMap = new HashMap<>(3); if (this.getSubject() instanceof Var || other.getSubject() instanceof Var) { substitutionMap.put(new TripleNode(this, this.getSubject(), 0), diff --git a/reasoner/src/main/java/eu/knowledge/engine/reasoner/api/TripleVarBindingSet.java b/reasoner/src/main/java/eu/knowledge/engine/reasoner/api/TripleVarBindingSet.java index e88c134d0..00cc21255 100644 --- a/reasoner/src/main/java/eu/knowledge/engine/reasoner/api/TripleVarBindingSet.java +++ b/reasoner/src/main/java/eu/knowledge/engine/reasoner/api/TripleVarBindingSet.java @@ -156,6 +156,10 @@ public String toString() { * @return */ public TripleVarBindingSet merge(TripleVarBindingSet aGraphBindingSet) { + + LOG.trace("Merging {} bindings with our {} bindings.", aGraphBindingSet.getBindings().size(), + this.getBindings().size()); + TripleVarBindingSet gbs = new TripleVarBindingSet(this.graphPattern); if (this.bindings.isEmpty()) { @@ -177,6 +181,9 @@ public TripleVarBindingSet merge(TripleVarBindingSet aGraphBindingSet) { }); } + LOG.trace("Merged {} bindings with our {} bindings into {} bindings.", aGraphBindingSet.getBindings().size(), + this.getBindings().size(), gbs.getBindings().size()); + return gbs; } @@ -251,6 +258,7 @@ public TripleVarBindingSet translate(Set graphPattern, Set newOne.add(toB); } } + LOG.trace("Translated binding set with '{}' bindings and '{}' matches.", this.bindings.size(), match.size()); return newOne; From 778d68fd7522fd275f2192c2c54f78fa03b613ac Mon Sep 17 00:00:00 2001 From: Barry Nouwt Date: Fri, 2 May 2025 08:34:06 +0200 Subject: [PATCH 2/2] Include progress logs for large binding sets. --- .../reasoner/api/TripleVarBindingSet.java | 28 ++++++++++++++++--- 1 file changed, 24 insertions(+), 4 deletions(-) diff --git a/reasoner/src/main/java/eu/knowledge/engine/reasoner/api/TripleVarBindingSet.java b/reasoner/src/main/java/eu/knowledge/engine/reasoner/api/TripleVarBindingSet.java index 00cc21255..391dcad5d 100644 --- a/reasoner/src/main/java/eu/knowledge/engine/reasoner/api/TripleVarBindingSet.java +++ b/reasoner/src/main/java/eu/knowledge/engine/reasoner/api/TripleVarBindingSet.java @@ -6,6 +6,7 @@ import java.util.Map; import java.util.Set; import java.util.concurrent.ConcurrentHashMap; +import java.util.concurrent.atomic.AtomicLong; import org.apache.jena.graph.Node; import org.apache.jena.sparql.core.Var; @@ -16,6 +17,8 @@ public class TripleVarBindingSet { + private static final int PROGRESS_MILESTONE_SIZE = 1000; + private static final int LARGE_BS_SIZE = 30000; private Set graphPattern; private Set bindings; private Set tripleVarsCache; @@ -162,6 +165,12 @@ public TripleVarBindingSet merge(TripleVarBindingSet aGraphBindingSet) { TripleVarBindingSet gbs = new TripleVarBindingSet(this.graphPattern); + final int otherBindingSetSize = aGraphBindingSet.getBindings().size(); + final long totalCount = (long) otherBindingSetSize * (long) this.getBindings().size(); + if (totalCount > LARGE_BS_SIZE) + LOG.warn("Merging 2 large BindingSets ({} * {} = {}). This can take some time.", + aGraphBindingSet.getBindings().size(), this.getBindings().size(), totalCount); + if (this.bindings.isEmpty()) { for (TripleVarBinding tvb2 : aGraphBindingSet.getBindings()) { gbs.add(tvb2); @@ -170,19 +179,29 @@ public TripleVarBindingSet merge(TripleVarBindingSet aGraphBindingSet) { // Cartesian product is the base case gbs.addAll(aGraphBindingSet.getBindings()); gbs.addAll(this.bindings); - this.bindings.stream().parallel().forEach(tvb1 -> { + AtomicLong progress = new AtomicLong(0); + + final int milestoneSize = PROGRESS_MILESTONE_SIZE; + AtomicLong nextMilestone = new AtomicLong(milestoneSize); + this.bindings.stream().parallel().forEach(tvb1 -> { for (TripleVarBinding otherB : aGraphBindingSet.getBindings()) { // always add a merged version of the two bindings, except when they conflict. if (!tvb1.isConflicting(otherB)) { gbs.add(tvb1.merge(otherB)); } } + final long current = progress.incrementAndGet(); + + if (totalCount > LARGE_BS_SIZE && current == nextMilestone.get()) { + LOG.trace("{}/{} BindingSet merge tasks done!", current * otherBindingSetSize, totalCount); + nextMilestone.set(current + milestoneSize); + } }); } - LOG.trace("Merged {} bindings with our {} bindings into {} bindings.", aGraphBindingSet.getBindings().size(), - this.getBindings().size(), gbs.getBindings().size()); + if (totalCount > LARGE_BS_SIZE) + LOG.debug("Merging large BindingSets done!"); return gbs; } @@ -258,8 +277,9 @@ public TripleVarBindingSet translate(Set graphPattern, Set newOne.add(toB); } } - LOG.trace("Translated binding set with '{}' bindings and '{}' matches.", this.bindings.size(), match.size()); + LOG.trace("Translated binding set with '{}' bindings and '{}' matches in '{}ms'.", this.bindings.size(), + match.size(), System.currentTimeMillis() - start); return newOne; }