diff --git a/opendj-server-legacy/src/main/java/org/opends/server/backends/jdbc/JDBCStorage.java b/opendj-server-legacy/src/main/java/org/opends/server/backends/jdbc/JDBCStorage.java index 3da7d5694a..8a41fb91e9 100644 --- a/opendj-server-legacy/src/main/java/org/opends/server/backends/jdbc/JDBCStorage.java +++ b/opendj-server-legacy/src/main/java/org/opends/server/backends/jdbc/JDBCStorage.java @@ -2844,7 +2844,7 @@ public void removeStorageFiles() throws StorageRuntimeException { // the catalog names what this backend owns, and only that: listTrees() also names the // shared compressed schema trees, which another backend of this database may be the only // owner of and which a clear must therefore leave exactly where they lie (#881) - final List skippedRows=new ArrayList<>(); // rows the read could not act on: reported below + final SkippedRows skippedRows=new SkippedRows(); // rows the read could not act on: reported below final Map trees=catalogTables(con, scope, skippedRows); final ClearCounts counts; try { @@ -2929,13 +2929,23 @@ ClearCounts dropCatalogTables(Connection con, TableScope scope, Map { final ClearCounts counts=new ClearCounts(); + // rows whose table was not there, and how many of them were named in a line of their own. + // Both are read off the catalog: a row of this kind is one another writer may have put + // there, so nothing this backend does bounds how many of them a clear meets, and neither + // value of the line is bounded either - a tree name is anything at all with two slashes in + // it, and the recorded name has been through isOwnTableName(), which bounds the characters + // of it and not the length. See MAX_REPORTED_VALUES and MAX_LOGGED_VALUE_LENGTH + int missingRows=0; for (final Map.Entry tree : trees.entrySet()) { final String tableName=tree.getValue(); final boolean isCatalog=catalogTree.equals(tree.getKey()); if (!isExistsTable(con, scope, tableName)) { // a row of the catalog outliving its table - reportClearLine(LocalizableMessage.raw( - "jdbc: backend %s names tree %s, whose table %s is not there: nothing to drop for it", - config.getBackendId(), tree.getKey(), tableName)); + missingRows++; + if (missingRows<=MAX_REPORTED_VALUES) { + reportClearLine(LocalizableMessage.raw( + "jdbc: backend %s names tree %s, whose table %s is not there: nothing to drop for it", + config.getBackendId(), forLog(tree.getKey().toString()), forLog(tableName))); + } if (!isCatalog) { counts.missingTrees++; } @@ -2947,6 +2957,14 @@ ClearCounts dropCatalogTables(Connection con, TableScope scope, MapMAX_REPORTED_VALUES) { + reportClearLine(LocalizableMessage.raw( + "jdbc: backend %s: %d row(s) of its catalog name a tree whose table is not there and the first %d of them are named above, the rest having gone by without a line of their own: there was nothing to drop for any of them", + config.getBackendId(), missingRows, MAX_REPORTED_VALUES)); + } con.commit(); return counts; }); @@ -3037,7 +3055,7 @@ void reportClearLine(LocalizableMessage line) { * what it can say. Without the term it says nothing at all, which is the silence of #888. */ void reportClearOutcome(Connection con, TableScope scope, int dropped, int droppedTrees, int missingTrees, - List skippedRows) { + SkippedRows skippedRows) { final ClearLeftovers leftovers=leftoverTables(con, scope); if (leftovers==null) { // a line of its own and not a clause of the one below: this says nothing about whether @@ -3077,15 +3095,15 @@ void reportClearOutcome(Connection con, TableScope scope, int dropped, int dropp reportSkippedRows(skippedRows); // after the reason above and among the lists, being a list itself if (ours>0) { reportClearLine(LocalizableMessage.raw("jdbc: backend %s: %d table(s) of %s hold trees of this backend that its catalog does not name, and the clear left them where they are: %s. A tree is enrolled as it is opened read-write and by no other means, so such a table is one of a tree of a base DN this backend still serves that was taken out of the configuration while it was disabled - an attribute index, say - or one left by a version keeping no catalog: it is this backend's own and can be removed by hand, and re-adding the tree it belongs to adopts it with the rows it still holds", - config.getBackendId(), ours, scope.name(), leftovers.ours)); + config.getBackendId(), ours, scope.name(), forLog(leftovers.ours))); } if (unattributed>0) { reportClearLine(LocalizableMessage.raw("jdbc: backend %s: %d opendj table(s) of %s are named by no catalog of this backend and carry no tree stamp, so nothing says whose they are: %s. They may hold the trees of a backend sharing this database, which nothing forbids, or be leftovers of a version stamping no table at all - a table is named after the hash of its tree name and can be attributed by no other means. They were left exactly where they are", - config.getBackendId(), unattributed, scope.name(), leftovers.unattributed)); + config.getBackendId(), unattributed, scope.name(), forLog(leftovers.unattributed))); } if (unreadable>0) { reportClearLine(LocalizableMessage.raw("jdbc: backend %s: the stamp of %d opendj table(s) of %s could not be read, so this clear says nothing about whose they are: %s. They were left exactly where they are", - config.getBackendId(), unreadable, scope.name(), leftovers.unreadable)); + config.getBackendId(), unreadable, scope.name(), forLog(leftovers.unreadable))); } } @@ -3109,13 +3127,123 @@ private static String removedTrees(int droppedTrees) { * table went on its own between the two lookups, it took them with it just the same. That is what * the line has to say, and why it carries the recorded name rather than sending an operator to a * table that is no longer there. + *

+ * Not private: it asks the database nothing and writes to nothing but {@link #reportClearLine}, so + * the bounds of the line it builds are held to by a case that calls it with an accumulator filled by + * hand - {@code ClearReportTestCase} - rather than by a case that has to reach them through a clear. */ - private void reportSkippedRows(List skippedRows) { + void reportSkippedRows(SkippedRows skippedRows) { if (skippedRows.isEmpty()) { return; } + // the count is every row passed over and the listing is the first of them: see SkippedRows for + // why the two are not the same number, and forLog() for the state each description reaches here in reportClearLine(LocalizableMessage.raw("jdbc: backend %s: %d row(s) of its catalog named nothing this clear could drop and were passed over: %s. The rows are gone with the catalog table, which a clear drops last; whatever they record was left standing, and no other line of this clear names it: the tables of this backend are named after the hash of a tree name, so what such a row records is outside the names a clear can account for. This line is the only surviving copy of it. A catalog holding such a row was written into by something other than this backend", - config.getBackendId(), skippedRows.size(), skippedRows)); + config.getBackendId(), skippedRows.size(), skippedRows.reported())); + } + + /** + * How many values of a list a line of this report carries. The lists it renders are read off the + * database - the rows of a catalog another writer put them in, the tables of a schema - so none of + * them is bounded by anything this backend does, and a catalog holding a million rows it cannot act + * on would otherwise be one log record of a million descriptions. What is left out is counted: the + * count beside every one of these lists is the whole of it, and the listing says how much of itself + * it is not showing. + */ + static final int MAX_REPORTED_VALUES=20; + + /** + * How much of one such value a line carries. The columns behind them bound almost nothing - the key + * of a catalog row is {@code bytea} on postgresql and {@code varbinary(max)} on sql server, the + * recorded table name a blob on every engine - so a single row is enough for the multi-megabyte + * record the cap above exists to rule out, and the cap above would not catch it. + */ + static final int MAX_LOGGED_VALUE_LENGTH=200; + + /** + * A value read out of the database as it may be logged: bounded, and with nothing in it that ends a + * log record. Every value these lines carry comes out of a table - the key of a catalog row, the + * table name it records, the comment a table is stamped with - and the whole premise of the lines + * carrying them is a database written into by something other than this backend, so a newline in one + * of them splices arbitrary text into the server log where it reads as further records. That is the + * one thing the escape is for: control characters are rendered rather than passed on, and the two + * unicode separators with them, since a reader that folds those breaks the same way. + *

+ * A backslash is left as it stands. It cannot end a record, and escaping it would spell every + * ordinary escaped comma of a normalized DN {@code \\,} - which is the wrong trade for a line an + * operator reads: what is being ruled out is a record split in two, not an ambiguous rendering. + *

+ * {@link CachedConnection#redact} is the nearest thing to this in the package - a value that reaches + * a log going through something first - for a different reason: what that one keeps out of the log + * is this backend's own credentials, what this one keeps out is somebody else's log records. + */ + static String forLog(String value) { + if (value==null) { + return null; + } + int kept=Math.min(value.length(), MAX_LOGGED_VALUE_LENGTH); + // never cut a surrogate pair in half: the cap counts code units, and a key decoded from a + // four-byte sequence is a pair, so a cut between the two leaves a high surrogate standing on + // its own - which is no control character and no separator, reaches the line as it is, and is + // written out as U+FFFD or "?" by whatever encoder the log has. The unit given back is counted + // by the tail below like any other + if (keptkept) { + escaped.append("...(+").append(value.length()-kept).append(" more characters)"); + } + return escaped.toString(); + } + + /** + * The same of a list of them: the first {@link #MAX_REPORTED_VALUES}, each through {@link + * #forLog(String)}, and a count of what the line is not naming. The count of the whole list is + * printed beside every one of these listings by the caller, so what is dropped here is dropped from + * the naming alone. + */ + static String forLog(Collection values) { + final StringBuilder rendered=new StringBuilder("["); + int named=0; + for (final String value : values) { + if (named==MAX_REPORTED_VALUES) { + break; + } + if (named>0) { + rendered.append(", "); + } + rendered.append(forLog(value)); + named++; + } + rendered.append(']'); + if (values.size()>named) { + rendered.append(" (and ").append(values.size()-named).append(" more, not named here)"); + } + return rendered.toString(); } /** @@ -3124,6 +3252,58 @@ private void reportSkippedRows(List skippedRows) { */ private static final String CLEAR_DROPPED_NOTHING="A backend upgraded from a version keeping no catalog has to be started once before its first offline \"import-ldif --clearBackend\": nothing enrols a tree before the clear runs, so that first clear finds a catalog that is not there - or, where the tables were restored from a backup taken beside an older one, a catalog that is there and names nothing - and removes no tree either way"; + /** + * The rows of a catalog a read passed over: how many there were, and a description of the first of + * them. Both numbers are the report's - see {@link #reportSkippedRows} - and they are kept apart for + * the reason {@link #MAX_REPORTED_VALUES} exists: a row of this kind is one another writer put in + * the catalog, so nothing bounds how many of them a read meets, and a clear that describes every one + * of them holds the whole catalog in a list until it reports. What an operator needs from the line + * is what such a row looks like and how many there are, and neither of those wants the millionth + * description. + *

+ * The descriptions arrive escaped and bounded, {@link #forLog(String)} having been applied to every + * value embedded in them where they were built: what is held here is what a log record may carry. + */ + static final class SkippedRows { + private final List descriptions=new ArrayList<>(); + private int passedOver; + + /** + * Takes one description, and answers whether this row is one of the described - which is also + * whether it is worth a line of its own, the per-row warns of {@link #readCatalogRows} being + * bounded by this same cap and for the same reason. + */ + boolean add(String description) { + passedOver++; + if (descriptions.size() descriptions() { + return descriptions; + } + + /** The descriptions as a line carries them, saying how many rows they are not describing. */ + String reported() { + return passedOver>descriptions.size() + ? descriptions+" (and "+(passedOver-descriptions.size())+" more, not described here)" + : descriptions.toString(); + } + } + /** What a clear left standing, told apart by the tree stamp of each table; see {@link #reportClearOutcome}. */ static final class ClearLeftovers { /** Tables whose stamp names a tree of this backend: its own, and removable by hand. */ @@ -3194,7 +3374,7 @@ ClearLeftovers leftoverTables(Connection con, TableScope scope) { // the read that failed is rolled back before the next table is asked about. There is // nothing pending to lose - the clear committed its drops before this ran logger.trace(LocalizableMessage.raw("jdbc: unable to read the stamp of table %s: %s", - tableName, stackTraceToSingleLineString(e))); + forLog(tableName), stackTraceToSingleLineString(e))); leftovers.unreadable.add(tableName); try { con.rollback(); @@ -5369,7 +5549,7 @@ Set listTrees(Connection con) throws SQLException { * lookup of their own by it, so they pass what they have instead of every reader asking twice over. */ Map catalogTables(Connection con, TableScope scope) throws SQLException { - return catalogTables(con, scope, new ArrayList<>()); // nobody to tell: the descriptions go nowhere + return catalogTables(con, scope, new SkippedRows()); // nobody to tell: the descriptions go nowhere } /** @@ -5378,7 +5558,7 @@ Map catalogTables(Connection con, TableScope scope) throws SQLE * such a row records is outside the namespace {@link #leftoverTables} scans. See {@link * #reportClearOutcome}. */ - Map catalogTables(Connection con, TableScope scope, List skippedRows) throws SQLException { + Map catalogTables(Connection con, TableScope scope, SkippedRows skippedRows) throws SQLException { final TreeName catalogTree=getCatalogTree(); final String catalogTable=getTableName(catalogTree); // narrowed to this database: a catalog of the same name in another database of the server @@ -5413,14 +5593,20 @@ Map catalogTables(Connection con, TableScope scope, List + * Both the warns and the descriptions are bounded, by the one cap and for the one reason: nothing + * this backend does bounds how many such rows a catalog holds, since a catalog holding any of them + * was written into by something else. Every value either of them embeds goes through {@link + * #forLog(String)} first - the key of the row, the tree name it spells, the table name it records - + * and one line at the end says how many rows were passed over in silence. See {@link SkippedRows}. */ Map readCatalogRows(Connection con, String catalogTable) throws SQLException { - return readCatalogRows(con, catalogTable, new ArrayList<>()); + return readCatalogRows(con, catalogTable, new SkippedRows()); } - Map readCatalogRows(Connection con, String catalogTable, List skippedRows) + Map readCatalogRows(Connection con, String catalogTable, SkippedRows skippedRows) throws SQLException { final Map trees=new LinkedHashMap<>(); // the rows are read inside the bound rather than from a live ResultSet: #882 took the @@ -5430,9 +5616,13 @@ Map readCatalogRows(Connection con, String catalogTable, List readCatalogRows(Connection con, String catalogTable, List readCatalogRows(Connection con, String catalogTable, List readCatalogRows(Connection con, String catalogTable, ListMAX_REPORTED_VALUES) { + logger.warn(LocalizableMessage.raw("jdbc: table %s holds %d row(s) this backend could not act on: the first %d are named above, the rest were passed over without a line of their own", + catalogTable, skippedRows.size(), MAX_REPORTED_VALUES)); + } return trees; } diff --git a/opendj-server-legacy/src/test/java/org/opends/server/backends/jdbc/ClearReportTestCase.java b/opendj-server-legacy/src/test/java/org/opends/server/backends/jdbc/ClearReportTestCase.java new file mode 100644 index 0000000000..afc8428d85 --- /dev/null +++ b/opendj-server-legacy/src/test/java/org/opends/server/backends/jdbc/ClearReportTestCase.java @@ -0,0 +1,297 @@ +/* + * The contents of this file are subject to the terms of the Common Development and + * Distribution License (the License). You may not use this file except in compliance with the + * License. + * + * You can obtain a copy of the License at legal/CDDLv1.0.txt. See the License for the + * specific language governing permission and limitations under the License. + * + * When distributing Covered Software, include this CDDL Header Notice in each file and include + * the License file at legal/CDDLv1.0.txt. If applicable, add the following below the CDDL + * Header, with the fields enclosed by brackets [] replaced by your own identifying + * information: "Portions copyright [year] [name of copyright owner]". + * + * Copyright 2026 3A Systems, LLC. + */ +package org.opends.server.backends.jdbc; + +import org.forgerock.i18n.LocalizableMessage; +import org.forgerock.opendj.server.config.server.JDBCBackendCfg; +import org.opends.server.DirectoryServerTestCase; +import org.testng.annotations.Test; + +import java.sql.Connection; +import java.util.ArrayList; +import java.util.List; + +import static org.forgerock.opendj.config.ConfigurationMock.mockCfg; +import static org.mockito.Mockito.when; +import static org.testng.Assert.assertEquals; +import static org.testng.Assert.assertFalse; +import static org.testng.Assert.assertTrue; + +/** + * What the account a clear gives of itself may carry (#931): every value in those lines was read + * out of the database, and the lines carrying them exist for a database written into by something + * other than this backend - so a value is bounded before it reaches one, and nothing in it may end + * a log record. + *

+ * None of it needs a database. The escape and the caps are pure functions, and the line itself is + * built by {@code reportSkippedRows()} out of an accumulator a case can fill by hand - which is why + * these are kept out of the container suites: those skip themselves whole where no docker is + * reachable, and a bound nothing exercises is a bound that can be deleted without a single test + * going red. + */ +@SuppressWarnings("javadoc") +public class ClearReportTestCase extends DirectoryServerTestCase { + + /** A storage with no database behind it, collecting the lines of a clear's report. */ + private static final class ReportedLines extends JDBCStorage { + private final List lines = new ArrayList<>(); + + /** + * What the scan of what a clear left standing answered, handed in rather than looked up: the + * lists of {@code reportClearOutcome()} are the tables of a schema and the stamps they carry, + * and a stamp is a comment somebody else may write. Asked of a database they would be this + * backend's own tables and nothing else - which is the one input the lines are not written for. + */ + private ClearLeftovers leftovers = new ClearLeftovers(); + + ReportedLines() { + super(backendCfg(), null); + } + + private static JDBCBackendCfg backendCfg() { + final JDBCBackendCfg cfg = mockCfg(JDBCBackendCfg.class); + when(cfg.getBackendId()).thenReturn("clearReport"); + return cfg; + } + + @Override + void reportClearLine(LocalizableMessage line) { + lines.add(line.toString()); + } + + @Override + ClearLeftovers leftoverTables(Connection con, TableScope scope) { + return leftovers; + } + + /** The outcome of a clear which dropped nothing, so that the lists below are what it has to say. */ + void reportOutcome() { + reportClearOutcome(null, TableScope.of(this, null, false), 0, 0, 0, new SkippedRows()); + } + } + + /** + * The characters a value must not reach a log record as: the ones that end one, and the two + * unicode separators a reader may fold the same way. Built rather than written out - a source + * file holding them as they stand is one nobody can review. + */ + private static final String SPLICED = "a_table\nSEVERE: a record of somebody else's\r\ttail" + + (char) 0x00 + (char) 0x85 + (char) 0x2028 + (char) 0x2029; + + /** The one thing the escape exists for: a value that would end the record it is written into. */ + @Test + public void testForLogEscapesWhatWouldEndALogRecord() { + final String escaped = JDBCStorage.forLog(SPLICED); + for (int i = 0; i < escaped.length(); i++) { + assertFalse(Character.isISOControl(escaped.charAt(i)), + "a control character reached the line as it stood, at " + i + ": " + escaped); + } + assertFalse(escaped.indexOf(0x2028) >= 0, "a line separator reached the line as it stood: " + escaped); + assertFalse(escaped.indexOf(0x2029) >= 0, "a paragraph separator reached the line as it stood: " + escaped); + assertTrue(escaped.contains("\\n"), "the newline is not rendered at all: " + escaped); + assertTrue(escaped.contains("\\r"), "the carriage return is not rendered at all: " + escaped); + assertTrue(escaped.contains("\\t"), "the tab is not rendered at all: " + escaped); + assertTrue(escaped.contains("\\u0000"), "the nul is not rendered at all: " + escaped); + assertTrue(escaped.contains("\\u0085"), "the next-line control is not rendered at all: " + escaped); + assertTrue(escaped.contains("\\u2028"), "the line separator is not rendered at all: " + escaped); + assertTrue(escaped.contains("\\u2029"), "the paragraph separator is not rendered at all: " + escaped); + // escaped and not dropped: what such a row holds is the whole of what the line has to say about + // it, and an operator who cannot read it is being told a row was passed over and nothing else + assertTrue(escaped.contains("SEVERE: a record of somebody else's"), + "the text of the value was dropped rather than escaped: " + escaped); + } + + /** + * A value is bounded as well as escaped: the key of a catalog row is {@code bytea} on postgresql + * and {@code varbinary(max)} on sql server, so one row is enough for the multi-megabyte record + * that the cap on the number of rows does not catch. + */ + @Test + public void testForLogBoundsHowMuchOfAValueALineCarries() { + // every character of its own: a value of 5000 identical ones has every substring of it equal to + // every other, so an escape keeping the last 200 - or every twenty-fifth - renders the same + // string and passes. What an operator recognises a value by is its head, and that is the thing + // asserted below + final StringBuilder huge = new StringBuilder(); + for (int i = 0; i < 5000; i++) { + huge.append((char) ('a' + i % 26)); + } + final String escaped = JDBCStorage.forLog(huge.toString()); + assertTrue(escaped.length() < JDBCStorage.MAX_LOGGED_VALUE_LENGTH + 64, + "the whole of a 5000 character value reached the line: " + escaped.length() + " characters"); + assertTrue(escaped.startsWith(huge.substring(0, JDBCStorage.MAX_LOGGED_VALUE_LENGTH)), + "the line does not show the head of the value it carries: " + escaped); + assertTrue(escaped.contains("(+" + (5000 - JDBCStorage.MAX_LOGGED_VALUE_LENGTH) + " more characters)"), + "the line does not say how much of the value it is not showing: " + escaped); + } + + /** + * And cuts between characters and not inside one. The cap counts code units, so a key decoded from + * a four-byte sequence - a surrogate pair - can straddle it, and a cut between the two leaves a + * high surrogate standing on its own: no control character, no separator, and written out as + * U+FFFD or "?" by whatever encoder the log has. + */ + @Test + public void testForLogDoesNotCutASupplementaryCharacterInHalf() { + final StringBuilder value = new StringBuilder(); + for (int i = 0; i < JDBCStorage.MAX_LOGGED_VALUE_LENGTH - 1; i++) { + value.append('x'); + } + value.appendCodePoint(0x1F600); // two units: the second of them is on the far side of the cap + value.append("tail"); + + final String escaped = JDBCStorage.forLog(value.toString()); + for (int i = 0; i < escaped.length(); i++) { + final char c = escaped.charAt(i); + if (Character.isHighSurrogate(c)) { + assertTrue(i + 1 < escaped.length() && Character.isLowSurrogate(escaped.charAt(i + 1)), + "a surrogate pair was cut in half at " + i + ": " + escaped); + } + assertFalse(Character.isLowSurrogate(c) && (i == 0 || !Character.isHighSurrogate(escaped.charAt(i - 1))), + "a low surrogate reached the line on its own at " + i + ": " + escaped); + } + // the unit given back is counted by the tail like any other: 199 kept of 205 + assertTrue(escaped.contains("(+" + (value.length() - (JDBCStorage.MAX_LOGGED_VALUE_LENGTH - 1)) + + " more characters)"), + "the line does not count the unit the cut gave back: " + escaped); + } + + /** + * And leaves alone what an operator has to read. A backslash is not escaped: it ends no record, + * and escaping it would spell every escaped comma of a normalized DN twice over. + */ + @Test + public void testForLogLeavesAnOrdinaryNameAsItIs() { + final String treeName = "/dc\\=example\\,inc,dc\\=com/id2entry"; + assertEquals(JDBCStorage.forLog(treeName), treeName, "an ordinary tree name was rewritten"); + } + + /** A list is bounded in its turn, and says how many of its values the line is not naming. */ + @Test + public void testForLogNamesOnlyTheFirstOfALongList() { + final List tables = new ArrayList<>(); + for (int i = 0; i < 100; i++) { + tables.add(String.format("opendj_t%02d", i)); + } + final String rendered = JDBCStorage.forLog(tables); + assertTrue(rendered.contains("opendj_t00"), "the first value of the list is not named: " + rendered); + assertTrue(rendered.contains(String.format("opendj_t%02d", JDBCStorage.MAX_REPORTED_VALUES - 1)), + "the list names fewer values than the cap allows: " + rendered); + assertFalse(rendered.contains(String.format("opendj_t%02d", JDBCStorage.MAX_REPORTED_VALUES)), + "the list names more values than the cap allows: " + rendered); + assertTrue(rendered.contains("(and " + (100 - JDBCStorage.MAX_REPORTED_VALUES) + " more, not named here)"), + "the list does not say how many values it is not naming: " + rendered); + } + + /** + * The accumulator counts every row and describes the first of them, and says which is which: what + * {@code add()} answers is whether the row it took is one of the described, which is what bounds + * the per-row warns of {@code readCatalogRows()} as well. + */ + @Test + public void testSkippedRowsCountsEveryRowAndDescribesTheFirst() { + final JDBCStorage.SkippedRows skipped = new JDBCStorage.SkippedRows(); + assertTrue(skipped.isEmpty(), "a fresh accumulator has rows in it"); + for (int i = 0; i < 100; i++) { + assertEquals(skipped.add("row " + i), i < JDBCStorage.MAX_REPORTED_VALUES, + "row " + i + " was described on the wrong side of the cap"); + } + assertEquals(skipped.size(), 100, "the accumulator counted fewer rows than it was given"); + assertEquals(skipped.descriptions().size(), JDBCStorage.MAX_REPORTED_VALUES, + "the accumulator kept more descriptions than the cap allows: " + skipped.descriptions()); + assertTrue(skipped.reported().contains("(and " + (100 - JDBCStorage.MAX_REPORTED_VALUES) + + " more, not described here)"), + "the rendering does not say how many rows it is not describing: " + skipped.reported()); + } + + /** + * The line itself, which is where all of it lands: the count is every row passed over, the naming + * is bounded, and nothing in it ends the record. The values arrive escaped, {@code + * readCatalogRows()} having put every one of them through {@code forLog()} where it built the + * description - which this case does for itself, exactly as that read does. + */ + @Test + public void testTheLineOfPassedOverRowsIsBoundedAndCarriesNoControlCharacter() { + final ReportedLines storage = new ReportedLines(); + final JDBCStorage.SkippedRows skipped = new JDBCStorage.SkippedRows(); + for (int i = 0; i < 100; i++) { + skipped.add(JDBCStorage.forLog("/dc=x/tree" + i + " at \"" + SPLICED + "\"")); + } + storage.reportSkippedRows(skipped); + + assertEquals(storage.lines.size(), 1, "the rows passed over were reported in " + storage.lines.size() + " lines"); + final String line = storage.lines.get(0); + assertTrue(line.contains("100 row(s)"), "the line does not count every row passed over: " + line); + assertFalse(line.indexOf('\n') >= 0, "the line can be split in two by a value it carries: " + line); + assertFalse(line.indexOf('\r') >= 0, "the line can be split in two by a value it carries: " + line); + assertTrue(line.contains("(and " + (100 - JDBCStorage.MAX_REPORTED_VALUES) + " more, not described here)"), + "the line describes every row it counted, or says nothing about the ones it left out: " + line); + } + + /** + * The other three lists a clear renders, and the road every one of them reaches a line by. They + * are the {@code opendj} tables of a schema and the stamps they carry: a table name is whatever + * the database was told to call it, a stamp is a comment somebody else may write, and neither is + * bounded by anything this backend does - a clear of a database several backends share can meet + * any number of them. + */ + @Test + public void testTheListsOfWhatAClearLeftStandingAreBoundedAndCarryNoControlCharacter() { + final ReportedLines storage = new ReportedLines(); + for (int i = 0; i < 100; i++) { + storage.leftovers.ours.add("opendj_o" + i + " (/dc=x/" + SPLICED + ")"); + storage.leftovers.unattributed.add("opendj_u" + i + SPLICED); + storage.leftovers.unreadable.add("opendj_r" + i + SPLICED); + } + storage.reportOutcome(); + + for (final String line : storage.lines) { + assertFalse(line.indexOf('\n') >= 0, "a line of the report can be split in two by a value it carries: " + line); + assertFalse(line.indexOf('\r') >= 0, "a line of the report can be split in two by a value it carries: " + line); + } + // one line per list: the count is the whole of it, the naming is the first of it, and it says + // how much of itself it is not showing + assertList(storage, "hold trees of this backend that its catalog does not name", "opendj_o0", "opendj_o99"); + assertList(storage, "are named by no catalog of this backend and carry no tree stamp", "opendj_u0", "opendj_u99"); + assertList(storage, "could not be read, so this clear says nothing about whose they are", "opendj_r0", "opendj_r99"); + } + + private static void assertList(ReportedLines storage, String marker, String named, String unnamed) { + final String line = lineHolding(storage, marker); + assertTrue(line.contains("100 "), "the list did not count the whole of itself: " + line); + assertTrue(line.contains(named), "the list does not name its first value: " + line); + assertFalse(line.contains(unnamed), "the list names more values than the cap allows: " + line); + assertTrue(line.contains("(and " + (100 - JDBCStorage.MAX_REPORTED_VALUES) + " more, not named here)"), + "the list does not say how many of its values it is not naming: " + line); + } + + private static String lineHolding(ReportedLines storage, String marker) { + for (final String line : storage.lines) { + if (line.contains(marker)) { + return line; + } + } + throw new AssertionError("no line of the report says \"" + marker + "\": " + storage.lines); + } + + /** And says nothing at all where there is nothing to say, which is every clear of a catalog this backend wrote. */ + @Test + public void testNoLineWhereNoRowWasPassedOver() { + final ReportedLines storage = new ReportedLines(); + storage.reportSkippedRows(new JDBCStorage.SkippedRows()); + assertTrue(storage.lines.isEmpty(), "a clear that passed over no row reported one: " + storage.lines); + } +} diff --git a/opendj-server-legacy/src/test/java/org/opends/server/backends/jdbc/TestCase.java b/opendj-server-legacy/src/test/java/org/opends/server/backends/jdbc/TestCase.java index 2a002a8c33..c701eb06e8 100644 --- a/opendj-server-legacy/src/test/java/org/opends/server/backends/jdbc/TestCase.java +++ b/opendj-server-legacy/src/test/java/org/opends/server/backends/jdbc/TestCase.java @@ -20,6 +20,7 @@ import org.forgerock.opendj.ldap.ByteStringBuilder; import org.forgerock.opendj.ldap.DN; import org.forgerock.opendj.server.config.server.JDBCBackendCfg; +import org.opends.server.TestCaseUtils; import org.opends.server.backends.pluggable.PluggableBackendImplTestCase; import org.opends.server.backends.pluggable.spi.AccessMode; import org.opends.server.backends.pluggable.spi.Cursor; @@ -47,6 +48,7 @@ import java.util.ArrayList; import java.util.Collection; import java.util.Collections; +import java.util.LinkedHashSet; import java.util.List; import java.util.Map; import java.util.NoSuchElementException; @@ -2597,12 +2599,13 @@ public void run(WriteableTransaction txn) throws Exception { recordAnotherTable(catalogTable, "a_table_of_something_else"); try (final Connection con = DriverManager.getConnection(getJdbcUrl())) { - final List skipped = new ArrayList<>(); + final JDBCStorage.SkippedRows skipped = new JDBCStorage.SkippedRows(); assertFalse(storage.readCatalogRows(con, catalogTable, skipped).containsKey(tree), "a row recording a name no table of this backend goes by was read as a tree to drop"); - assertEquals(skipped.size(), 1, "the row the read passed over was not described to its caller: " + skipped); - assertTrue(skipped.get(0).contains("a_table_of_something_else"), - "what the row records is named by nothing the clear could report: " + skipped); + assertEquals(skipped.size(), 1, + "the row the read passed over was not described to its caller: " + skipped.descriptions()); + assertTrue(skipped.descriptions().get(0).contains("a_table_of_something_else"), + "what the row records is named by nothing the clear could report: " + skipped.descriptions()); } // the clear still drops what it can: the catalog itself, which it names last @@ -2623,6 +2626,241 @@ public void run(WriteableTransaction txn) throws Exception { } } + /** + * The line above carries what the row recorded, and what the row recorded is a value somebody else + * wrote into this database - the premise of the line being a catalog written into by something + * other than this backend. A newline in it would splice the rest of the value into the server log + * as further records; #931. The clear runs against a database rather than the escape being asserted + * on its own, which is what pins the value going through it on the way to the line: the unit of it + * is {@code ClearReportTestCase}. + */ + @Test + public void testAClearDoesNotLetACatalogRowEndTheLineReportingIt() throws Exception { + final TreeName tree = new TreeName("testCatalogSplicedRow", "tree"); + final ReportingStorage storage = new ReportingStorage(createBackendCfg(getBackendId() + "_splicedRow")); + final String tableName = storage.getTableName(tree); + try { + storage.open(AccessMode.READ_WRITE); + storage.write(new WriteOperation() { + @Override + public void run(WriteableTransaction txn) throws Exception { + txn.openTree(tree, true); + } + }); + final String catalogTable = storage.getTableName(storage.getCatalogTree()); + recordAnotherTable(catalogTable, "a_table\nSEVERE: a record of somebody else's"); + + // the clear drops what it can - its own catalog - and reports the row it passed over + storage.removeStorageFiles(); + + storage.assertReported("the row the clear could not act on was reported by no line of it", + "a_table\\nSEVERE: a record of somebody else's", "passed over"); + for (final String line : storage.reported()) { + assertFalse(line.indexOf('\n') >= 0, + "a value read out of the catalog ended the line carrying it: " + line); + assertFalse(line.indexOf('\r') >= 0, + "a value read out of the catalog ended the line carrying it: " + line); + } + } finally { + clearQuietly(storage); + // left standing on purpose above, so this case removes it rather than the next one meeting it + dropTableIfExists(tableName); + } + } + + /** + * The same for the key of such a row, which is read as the name of a tree and reported where it is + * not one: {@code TreeName.valueOf()} asks for a slash at the front and another one after it and + * nothing else, so everything between and after is whatever the row holds. #931. + */ + @Test + public void testAClearDoesNotLetACatalogKeyThatNamesNoTreeEndTheLineReportingIt() throws Exception { + final TreeName tree = new TreeName("testCatalogSplicedKey", "tree"); + final ReportingStorage storage = new ReportingStorage(createBackendCfg(getBackendId() + "_splicedKey")); + final String tableName = storage.getTableName(tree); + try { + storage.open(AccessMode.READ_WRITE); + storage.write(new WriteOperation() { + @Override + public void run(WriteableTransaction txn) throws Exception { + txn.openTree(tree, true); + } + }); + final String catalogTable = storage.getTableName(storage.getCatalogTree()); + insertCatalogRow(catalogTable, "no-tree-name\nSEVERE: a record of somebody else's", "opendj_whatever"); + + storage.removeStorageFiles(); + + storage.assertReported("the row whose key names no tree was reported by no line of the clear", + "no-tree-name\\nSEVERE: a record of somebody else's", "passed over"); + assertNoLineIsSplit(storage); + } finally { + clearQuietly(storage); + dropTableIfExists(tableName); + } + } + + /** + * And for the line naming a tree whose table is not there, which carries two values off the one + * row: the tree name the key spells, and the name the row records - which {@code isOwnTableName()} + * bounds the characters of and not the length, {@code v} being a blob on every engine. #931. + */ + @Test + public void testAClearDoesNotLetTheRowOfAMissingTableEndTheLineReportingIt() throws Exception { + final TreeName tree = new TreeName("testCatalogSplicedMissingTable", "tree"); + final ReportingStorage storage = new ReportingStorage(createBackendCfg(getBackendId() + "_splicedMissing")); + final String tableName = storage.getTableName(tree); + final StringBuilder recorded = new StringBuilder("opendj"); + while (recorded.length() < 260) { // a bare identifier, and longer than any line may carry + recorded.append('q'); + } + try { + storage.open(AccessMode.READ_WRITE); + storage.write(new WriteOperation() { + @Override + public void run(WriteableTransaction txn) throws Exception { + txn.openTree(tree, true); + } + }); + final String catalogTable = storage.getTableName(storage.getCatalogTree()); + // a row naming a tree this backend never enrolled and recording a name of its own namespace + // that no table goes by: the clear finds nothing to drop for it, and says so naming both + insertCatalogRow(catalogTable, "/dc=spliced\nSEVERE: a record of somebody else's/tree", + recorded.toString()); + + storage.removeStorageFiles(); + + storage.assertReported("the row naming a tree whose table is not there was reported by no line", + "/dc=spliced\\nSEVERE: a record of somebody else's/tree", "is not there: nothing to drop for it"); + assertNoLineIsSplit(storage); + for (final String line : storage.reported()) { + assertFalse(line.contains(recorded.toString()), + "the whole of a 260 character name recorded by a row reached the line carrying it: " + line); + } + storage.assertReported("the line does not say how much of the recorded name it is not showing", + "more characters)"); + } finally { + clearQuietly(storage); + dropTableIfExists(tableName); + } + } + + /** + * And there is a bound on how many such rows are named at all. One line per row of a catalog is + * one line per row somebody else may have put there: the row reaches this line by recording a name + * of this backend's namespace that no table goes by, which nothing this backend does bounds the + * number of. What the clear reports as trees which had lost their table stays the count of them + * all. #931. + */ + @Test + public void testAClearBoundsHowManyRowsOfAMissingTableItNames() throws Exception { + final TreeName tree = new TreeName("testCatalogManyMissingTables", "tree"); + final ReportingStorage storage = new ReportingStorage(createBackendCfg(getBackendId() + "_manyMissing")); + final String tableName = storage.getTableName(tree); + final int rows = JDBCStorage.MAX_REPORTED_VALUES + 1; + try { + storage.open(AccessMode.READ_WRITE); + storage.write(new WriteOperation() { + @Override + public void run(WriteableTransaction txn) throws Exception { + txn.openTree(tree, true); + } + }); + final String catalogTable = storage.getTableName(storage.getCatalogTree()); + for (int i = 0; i < rows; i++) { + insertCatalogRow(catalogTable, "/dc=missing" + i + "/tree", "opendj_nosuchtable" + i); + } + + storage.removeStorageFiles(); + + int named = 0; + for (final String line : storage.reported()) { + if (line.contains("is not there: nothing to drop for it")) { + named++; + } + } + assertEquals(named, JDBCStorage.MAX_REPORTED_VALUES, + "a line was reported for every row whose table was not there: " + storage.reported()); + // the count the line states is every such row and not the twenty it named: what the cap + // takes away is the naming + storage.assertReported("the clear does not say how many rows it named no line for", + rows + " row(s) of its catalog name a tree whose table is not there", + "the first " + JDBCStorage.MAX_REPORTED_VALUES + " of them are named above"); + } finally { + clearQuietly(storage); + dropTableIfExists(tableName); + } + } + + /** + * The warnings a read of a catalog writes as it goes are bounded by the same cap, and for the same + * reason: a reader with nobody to tell - a read of {@code dbtest}, or the one an enrolment makes - + * has them as its whole report, and a catalog holding a million rows this backend cannot act on + * was a million records of the server log. One line at the end says how many rows went by without + * one, so that reader is not left believing the rows it was shown were all there were. #931. + */ + @Test + public void testAReadOfACatalogBoundsTheWarningsItWritesPerRow() throws Exception { + final TreeName tree = new TreeName("testCatalogManySkippedRows", "tree"); + final ReportingStorage storage = new ReportingStorage(createBackendCfg(getBackendId() + "_manySkipped")); + final String tableName = storage.getTableName(tree); + final int rows = JDBCStorage.MAX_REPORTED_VALUES + 1; + try { + storage.open(AccessMode.READ_WRITE); + storage.write(new WriteOperation() { + @Override + public void run(WriteableTransaction txn) throws Exception { + txn.openTree(tree, true); + } + }); + final String catalogTable = storage.getTableName(storage.getCatalogTree()); + for (int i = 0; i < rows; i++) { + insertCatalogRow(catalogTable, "no-tree-name" + i, "opendj_whatever"); + } + + final JDBCStorage.SkippedRows skipped = new JDBCStorage.SkippedRows(); + TestCaseUtils.clearLoggersContents(); + try (final Connection con = DriverManager.getConnection(getJdbcUrl())) { + storage.readCatalogRows(con, catalogTable, skipped); + } + // by the records that differ: the error log of a test run holds every one of them twice, + // each of the two publishers registered for it keeping its own copy + final Set warned = new LinkedHashSet<>(TestCaseUtils.ERROR_TEXT_WRITER.getMessages()); + + assertEquals(skipped.size(), rows, "the read counted fewer rows than it passed over"); + assertEquals(skipped.descriptions().size(), JDBCStorage.MAX_REPORTED_VALUES, + "the read described more rows than the cap allows: " + skipped.descriptions()); + assertEquals(countHolding(warned, "which is not the name of a tree: skipped"), + JDBCStorage.MAX_REPORTED_VALUES, + "a warning was written for every row the read passed over: " + warned); + assertEquals(countHolding(warned, "row(s) this backend could not act on"), 1, + "the read did not say once how many rows it passed over without a line of their own: " + warned); + } finally { + clearQuietly(storage); + dropTableIfExists(tableName); + } + } + + /** Fails unless every line a clear reported is one log record, which is what the escape is for. */ + private static void assertNoLineIsSplit(ReportingStorage storage) { + for (final String line : storage.reported()) { + assertFalse(line.indexOf('\n') >= 0, + "a value read out of the catalog ended the line carrying it: " + line); + assertFalse(line.indexOf('\r') >= 0, + "a value read out of the catalog ended the line carrying it: " + line); + } + } + + private static int countHolding(Collection records, String fragment) { + int held = 0; + for (final String record : records) { + if (record.contains(fragment)) { + held++; + } + } + return held; + } + /** * A clear drops the table its catalog records for a tree, not one it derives again from the tree * name, so that a removal drops what was enrolled even if the naming of tables were ever to @@ -2883,6 +3121,32 @@ private void recordAnotherTable(String catalogTable, String tableName) throws SQ } } + /** + * Puts a row into a catalog with a key of this case's own, which nothing this backend writes would + * make: every key it writes is a {@code TreeName.toString()} and every value a name it derived + * itself. The premise of the lines these cases hold to account is a catalog written into by + * something other than this backend, and this is what writes into one. + *

+ * By hand and not through the storage, which has no way of enrolling a tree under a name of + * somebody else's choosing. {@code h} is the column a key is sought by and no part of the + * {@code select k,v} a clear reads the catalog with, so anything unique will do - unique because + * it alone is the primary key on sql server - and the key goes through {@code real2db()} exactly + * as an enrolment puts it there. + */ + private void insertCatalogRow(String catalogTable, String key, String tableName) throws SQLException { + try (final Connection con = DriverManager.getConnection(getJdbcUrl()); + final PreparedStatement statement = con.prepareStatement( + "insert into " + catalogTable + " (h,k,v) values (?,?,?)")) { + statement.setString(1, "byHand" + rowsPutInByHand.incrementAndGet()); + statement.setBytes(2, JDBCStorage.real2db(key.getBytes(StandardCharsets.UTF_8))); + statement.setBytes(3, tableName.getBytes(StandardCharsets.UTF_8)); + statement.executeUpdate(); + } + } + + /** Tells one such row from the next: see {@link #insertCatalogRow}. */ + private static final AtomicInteger rowsPutInByHand = new AtomicInteger(); + /** Empties the recorded table name of every row of a catalog, as a version recording none would have left it. */ private void emptyTheRecordedTableNames(String catalogTable) throws SQLException { try (final Connection con = DriverManager.getConnection(getJdbcUrl());