This is an automated email from the ASF dual-hosted git repository. reschke pushed a commit to branch OAK-10643 in repository https://gitbox.apache.org/repos/asf/jackrabbit-oak.git
commit b2107105d658ff05701fdab90f234939102af37a Author: Julian Reschke <[email protected]> AuthorDate: Tue Feb 13 19:13:24 2024 +0100 OAK-10643: MongoDocumentStore: improve diagnostics for too large docs --- .../plugins/document/mongo/MongoDocumentStore.java | 26 +++++++- .../oak/plugins/document/util/Utils.java | 69 ++++++++++++++++++++++ .../plugins/document/BasicDocumentStoreTest.java | 33 ++++++++++- 3 files changed, 124 insertions(+), 4 deletions(-) diff --git a/oak-store-document/src/main/java/org/apache/jackrabbit/oak/plugins/document/mongo/MongoDocumentStore.java b/oak-store-document/src/main/java/org/apache/jackrabbit/oak/plugins/document/mongo/MongoDocumentStore.java index 1f156f4100..c37e06cfcd 100644 --- a/oak-store-document/src/main/java/org/apache/jackrabbit/oak/plugins/document/mongo/MongoDocumentStore.java +++ b/oak-store-document/src/main/java/org/apache/jackrabbit/oak/plugins/document/mongo/MongoDocumentStore.java @@ -1055,6 +1055,8 @@ public class MongoDocumentStore implements DocumentStore { } final Stopwatch watch = startWatch(); boolean newEntry = false; + T oldDoc = null; + try { // get modCount of cached document Long modCount = null; @@ -1122,7 +1124,8 @@ public class MongoDocumentStore implements DocumentStore { if (checkConditions && oldNode == null) { return null; } - T oldDoc = convertFromDBObject(collection, oldNode); + + oldDoc = convertFromDBObject(collection, oldNode); if (oldDoc != null) { if (collection == Collection.NODES) { NodeDocument newDoc = (NodeDocument) applyChanges(collection, oldDoc, updateOp); @@ -1145,8 +1148,8 @@ public class MongoDocumentStore implements DocumentStore { return oldDoc; } catch (MongoWriteException e) { WriteError werr = e.getError(); - LOG.error("Failed to update the document with Id={} with MongoWriteException message = '{}'.", - updateOp.getId(), werr.getMessage()); + LOG.error("Failed to update the document with Id={} with MongoWriteException message = '{}'. Document statistics: {}.", + updateOp.getId(), werr.getMessage(), produceDiagnostics(collection, updateOp.getId()), e); throw handleException(e, collection, updateOp.getId()); } catch (MongoCommandException e) { LOG.error("Failed to update the document with Id={} with MongoCommandException message ='{}'. ", @@ -1163,6 +1166,23 @@ public class MongoDocumentStore implements DocumentStore { } } + private <T extends Document> String produceDiagnostics(Collection<T> col, String id) { + StringBuilder t = new StringBuilder(); + + try { + T doc = find(col, id); + if (doc != null) { + t.append("_id: " + doc.getId() + ", _modCount: " + doc.getModCount() + ", memory: " + doc.getMemory()); + t.append("; Contents: "); + t.append(Utils.mapEntryDiagnostics(doc.entrySet())); + } + } catch (Throwable thisIsBestEffort) { + t.append(thisIsBestEffort.getMessage()); + } + + return t.toString(); + } + /** * Try to apply all the {@link UpdateOp}s with at least MongoDB requests as * possible. The return value is the list of the old documents (before diff --git a/oak-store-document/src/main/java/org/apache/jackrabbit/oak/plugins/document/util/Utils.java b/oak-store-document/src/main/java/org/apache/jackrabbit/oak/plugins/document/util/Utils.java index 793e3a9433..cacc27d0ff 100644 --- a/oak-store-document/src/main/java/org/apache/jackrabbit/oak/plugins/document/util/Utils.java +++ b/oak-store-document/src/main/java/org/apache/jackrabbit/oak/plugins/document/util/Utils.java @@ -26,12 +26,14 @@ import java.sql.Timestamp; import java.time.Instant; import java.time.format.DateTimeFormatter; import java.util.ArrayList; +import java.util.Collections; import java.util.Comparator; import java.util.Date; import java.util.Iterator; import java.util.List; import java.util.Map; import java.util.Map.Entry; +import java.util.Set; import java.util.SortedMap; import java.util.TreeMap; @@ -206,6 +208,73 @@ public class Utils { return (int) size; } + public static String mapEntryDiagnostics(@NotNull Set<Entry<String, Object>> entries) { + StringBuilder t = new StringBuilder(); + Map<String, Map.Entry<Integer, Long>> stats = new TreeMap<>(); + + for (Map.Entry<String, Object> member : entries) { + String key = member.getKey(); + Integer count = 0; + Long size = 0L; + + Map.Entry<Integer, Long> stat = stats.get(key); + if (stat != null) { + count = stat.getKey(); + size = stat.getValue(); + } + + Object o = member.getValue(); + if (o instanceof String) { + size += StringUtils.estimateMemoryUsage((String) o); + count += 1; + } else if (o instanceof Long) { + size += 16; + count += 1; + } else if (o instanceof Boolean) { + size += 8; + count += 1; + } else if (o instanceof Integer) { + size += 8; + count += 1; + } else if (o instanceof Map) { + @SuppressWarnings("unchecked") + Map<Object, Object> x = (Map<Object, Object>)o; + size += 8 + (long)Utils.estimateMemoryUsage(x); + count += x.size(); + } else if (o == null) { + // zero + } else { + throw new IllegalArgumentException("Can't estimate memory usage of " + o); + } + + stats.put(key, Map.entry(count, size)); + } + + List<Map.Entry<String, Map.Entry<Integer, Long>>> sorted = new ArrayList<Entry<String, Entry<Integer, Long>>>(stats.entrySet()); + + // sort by estimated entry size, highest first + Collections.sort(sorted, new Comparator<Map.Entry<String, Map.Entry<Integer, Long>>>() { + @Override + public int compare(Entry<String, Entry<Integer, Long>> o1, Entry<String, Entry<Integer, Long>> o2) { + return o2.getValue().getValue().compareTo(o1.getValue().getValue()); + } + }); + + String sep = ""; + for (Map.Entry<String, Map.Entry<Integer, Long>> member : sorted) { + t.append(sep + member.getKey() + ": "); + sep = ", "; + if (member.getValue().getKey() <= 1) { + t.append(member.getValue().getValue() + " bytes"); + } else { + t.append(member.getValue().getValue() + " bytes in " + member.getValue().getKey() + " entries (" + + member.getValue().getValue() / member.getValue().getKey() + " avg)"); + } + } + + return t.toString(); + } + public static String escapePropertyName(String propertyName) { int len = propertyName.length(); if (len == 0) { diff --git a/oak-store-document/src/test/java/org/apache/jackrabbit/oak/plugins/document/BasicDocumentStoreTest.java b/oak-store-document/src/test/java/org/apache/jackrabbit/oak/plugins/document/BasicDocumentStoreTest.java index 7bb094936e..8a416e2de8 100644 --- a/oak-store-document/src/test/java/org/apache/jackrabbit/oak/plugins/document/BasicDocumentStoreTest.java +++ b/oak-store-document/src/test/java/org/apache/jackrabbit/oak/plugins/document/BasicDocumentStoreTest.java @@ -577,7 +577,7 @@ public class BasicDocumentStoreTest extends AbstractDocumentStoreTest { int i = 0; for (i = 0; i < 32 && exception == null; i++) { - String pval = generateString(1024 * 1024, true); + String pval = generateString(1024 * 1024 + i * 10, true); String pname = String.format("foo%02d", i); up.set(pname, pval); try { @@ -598,6 +598,37 @@ public class BasicDocumentStoreTest extends AbstractDocumentStoreTest { LOG.info("max number of 1MB property additions for " + super.dsname + " was " + i + " (" + exception + ")"); } + @Test + public void testMaxAddPropertyUpdate() { + + String id = this.getClass().getName() + ".testMaxAddPropertyUpdate"; + UpdateOp up = new UpdateOp(id, true); + super.ds.create(Collection.NODES, Collections.singletonList(up)); + String exception = null; + + int i = 0; + for (i = 0; i < 32 && exception == null; i++) { + String pval = generateString(1024 * 1024 + i * 10, true); + String pname = "foo"; + up.setMapEntry(pname, new Revision(System.currentTimeMillis(), i, 0), pval); + try { + NodeDocument doc = super.ds.findAndUpdate(Collection.NODES, up); + if (doc != null) { + // check that we really can read it + NodeDocument findme = super.ds.find(Collection.NODES, id, 0); + assertNotNull("failed to retrieve previously stored document", findme); + assertNotNull(findme.get(pname)); + } + } catch (Throwable ex) { + LOG.error("trying to add " + i + "th 1MB property " + super.dsname + ": " + ex.getMessage(), ex); + exception = ex.getMessage(); + } + } + + super.ds.remove(Collection.NODES, id); + LOG.info("max number of 1MB property updates for " + super.dsname + " was " + i + " (" + exception + ")"); + } + @Test public void testInterestingPropLengths() throws UnsupportedEncodingException { int lengths[] = { 1, 10, 100, 1000, 2000, 3000, 4000, 5000, 6000, 7000, 8000, 9000, 10000, 11000, 12000, 13000, 14000,
