[#931] Bound and escape the values a clear's report reads out of the database

[vharseko]

Fixes #931

readCatalogRows() and reportSkippedRows() came from #893, which has since merged.

Problem

A clear accounts for every row of its catalog and for every opendj table it left standing, and both accounts are built out of values read back off the database: the key of a catalog row, the table name that row records, the comment a table is stamped with. The premise of those lines is a database written into by something other than this backend — so their input is untrusted by construction, and nothing bounded it.

// readCatalogRows(), before: one description per row, no cap, the values as they stand
skippedRows.add(treeName+" at \""+tableName+"\", which is no table of this backend");
...
// reportSkippedRows(), before: the whole List rendered into a single line
reportClearLine(LocalizableMessage.raw("jdbc: backend %s: %d row(s) of its catalog named nothing this clear could drop and were passed over: %s. ...",
    config.getBackendId(), skippedRows.size(), skippedRows));

No cap. A catalog holding a million rows this backend cannot act on was a million logger.warn records on the way in, a List of a million descriptions held for the whole of the clear, and one log record of all of them at the end.

A value could end the record carrying it. A newline in one of them splices the rest of itself into the server log where it reads as further records — the pattern CodeQL names log injection.

What the values actually are

• name — the whole of the k column, decoded as UTF-8, unchecked.
• treeName — TreeName.valueOf() requires a / at index 0 and another at index >= 2 (TreeName.java:53-60) and asks nothing else: everything between and after, control characters included, is whatever the row holds.
• tableName — the whole of the v column. In the branch that has just established it is none of this backend's names (isOwnTableName() rejected it), and in the one that has established it is: isOwnTableName() bounds the characters of a name and not its length.

The columns bound almost nothing — k raw(2000), v blob on oracle, k varbinary(255), v longblob on mysql, k varbinary(max), v image on sql server, k bytea, v bytea on postgresql — so a single row is enough for a multi-megabyte record, which a cap on the number of rows would not catch.

The same shape stands in the lines beside it: the "tables of this backend its catalog does not name" list embeds the stamp of each table, which is a comment somebody else may write, and the "names tree %s, whose table %s is not there" line carries both values of a row off the same catalog — and a row reaches that line by recording a name of this backend's namespace that no table goes by, which nothing this backend does bounds the number of.

Fix

• forLog(String) — renders \n, \r and \t as escapes, every other ISO control character and the two unicode separators as \uXXXX, and bounds the value at 200 characters with a ...(+K more characters) tail. It cuts between characters and never inside one: the cap counts code units, so a surrogate pair straddling it gives the unit back rather than leaving a high surrogate standing alone. A backslash is left alone: it ends no record, and escaping it would spell every escaped comma of a normalized DN twice over.
• forLog(Collection<String>) — the first 20 values, each through the above, and a count of what the line is not naming.
• SkippedRows — replaces the List<String>: it counts every row passed over and keeps the first 20 descriptions. What add() answers is whether the row is one of the described, which is what bounds the per-row warns of readCatalogRows() by the same cap; one line at the end of the read says how many rows went by without one.
• The "whose table %s is not there" line is bounded the same way twice over: both of its values go through forLog(), and the same cap bounds how many of those lines a clear reports, with one line where it cuts in.

Every count these lines state stays whole — %d row(s), %d table(s), counts.missingTrees — what is capped is the naming. CachedConnection.redact() is the nearest precedent in the package for a value that goes through something on its way to a log; this is the same shape for the opposite direction, keeping somebody else's records out rather than this backend's credentials.

reportSkippedRows() is no longer private: it asks the database nothing and writes to nothing but reportClearLine(), so the bounds of the line it builds are held to by a case that calls it directly.

This is not a red CodeQL alert

The repo scans with security-and-quality and has no java/log-injection alert here, and would not be expected to: a ResultSet read is a source only under the database threat model, which is off by default. The pattern is real; the fix is not chasing a failing check.

Tests

ClearReportTestCase needs no database — the escape and both caps are pure functions, the line of passed-over rows is built out of an accumulator a case fills by hand, and the three lists of reportClearOutcome() are handed in through leftoverTables() rather than asked of a schema, which is also the only way to put a stamp somebody else wrote into one. Keeping them out of the container suites is the point: those skip themselves whole where no docker is reachable, and a bound nothing exercises can be deleted without a test going red.

The container suites drive what only a real clear reaches. Nothing this backend writes puts a key of somebody else's choosing into a catalog, so insertCatalogRow() writes the row itself:

case	what it pins
testAClearDoesNotLetACatalogRowEndTheLineReportingIt	the recorded name of a row naming no table of this backend
testAClearDoesNotLetACatalogKeyThatNamesNoTreeEndTheLineReportingIt	the key of a row naming no tree
testAClearDoesNotLetTheRowOfAMissingTableEndTheLineReportingIt	both values of the "whose table is not there" line: the tree name by a newline, the recorded name by a 260 character name
testAClearBoundsHowManyRowsOfAMissingTableItNames	the cap on how many of those lines a clear reports
testAReadOfACatalogBoundsTheWarningsItWritesPerRow	the per-row warn gates of readCatalogRows() and the one line at the end of the read, off the error log of the run

suite	where	result
ClearReportTestCase	locally	9/9
PgSqlTestCase	locally, against a container	86/86, Skipped: 0
every forLog() call site, the two caps, the surrogate cut and the two warn gates	locally, one mutant each	11 mutants, all red, each killed by its own case and assertion

CI runs all of it: **/*TestCase.java is one of the failsafe includes (opendj-server-legacy/pom.xml:1249), and one ubuntu job of the previous round ran ClearReportTestCase 7/7 beside MsSqlTestCase 81/0, MySqlTestCase 81/0, OracleTestCase 81/0 and PgSqlTestCase 82/0 — the new container cases run in every one of those four.

Named rather than folded in

• One cap for both kinds of list. MAX_REPORTED_VALUES bounds the descriptions of passed-over rows, the listings of leftover tables and the lines naming a tree whose table is not there alike. The counts beside them stay exact, but on a database several backends share, the "named by no catalog" listing can now be a sample of a longer list. Two constants, or a larger one, if you would rather.
• A length bound on isOwnTableName() is not part of this. A recorded name longer than any engine's identifier still enters the map a clear walks and reaches the existence lookup; what this PR does is keep it out of a log record. Which names the drop path admits is [#888] Name the trees of a JDBC backend from a catalog in the database #893's rule and a question of its own, which gets an issue of its own together with the postgresql identifier truncation a length bound would also close.

[vharseko]

@maximthomas rebased onto master — the branch had gone conflicting against #885, which landed after this was opened and lifted the drop loop of a clear out of removeStorageFiles() into a dropCatalogTables() of its own, under a single DDL lock bound.

Exactly one line of this PR sat inside that loop and moved with it: the forLog() on the tree name of the "names tree %s, whose table %s is not there" report now sits in dropCatalogTables(). Everything else is line for line what it was — forLog() itself, both caps, SkippedRows, and every test — the indentation of that one hunk aside.

Re-run on the rebased commit, so the clear goes through the extracted method rather than the loop it was written against:

• ClearReportTestCase — 7/7
• PgSqlTestCase — 82/82, Skipped: 0, testAClearDoesNotLetACatalogRowEndTheLineReportingIt among them. 82 rather than the 80 of the first round because master gained cases in the meantime

The negative control in the description — forLog() taken back out, the reported line split in two by the value it carried — is the one row still from the first round; the branch it guards is unchanged, so taking the call out again fails the same case the same way.

Description updated to match. No review feedback has come in yet, so nothing else here has moved.

[maximthomas]

praise: The escape sits exactly where the untrusted value enters a log line, and its bounds are the ones the columns lack.

• JDBCStorage.forLog(String):3166 renders \n/\r/\t and every other ISO control plus U+2028/U+2029, caps at MAX_LOGGED_VALUE_LENGTH with the exact remainder, and leaves the backslash alone for the normalized-DN reason it states.
• SkippedRows.add() answers whether the row is described, and that one boolean is what bounds the per-row warns of readCatalogRows():5599/:5611/:5633 by the same cap while size() stays whole.
• The negative control in the description — forLog() taken out of the "no table of this backend" branch, the new TestCase case red with the line split in two — proves the road the real-clear case drives.

---

suggestion (non-blocking): The recorded table name on the "names tree %s, whose table %s is not there" line is unbounded in length: isOwnTableName() bounds the charset, not the length.

opendj-server-legacy/src/main/java/org/opends/server/backends/jdbc/JDBCStorage.java:2941, :5662-5673

The comment at :2936-2938 says the name "has been through isOwnTableName(), which leaves nothing but a bare identifier"; that method checks a case-insensitive opendj prefix and [A-Za-z0-9_$] and nothing about length, and v is a blob on every engine. A row whose v is opendj followed by megabytes of letters passes the :5631 branch into trees, isExistsTable() answers false for it, and :2941 renders the whole of it — the single-row multi-megabyte record the javadoc of MAX_LOGGED_VALUE_LENGTH (:3140-3146) exists to rule out. Reachable only by a foreign row, one line per such row. The description names this line as "escaped but not capped" and offers to bound it; this is the word.

// JDBCStorage.java:2941 — the recorded name through the same cap; the identity for every real identifier
config.getBackendId(), forLog(tree.getKey().toString()), forLog(tableName)));

Or: give isOwnTableName() the identifier bound the engines have anyway (63 postgresql, 64 mysql, 128 sql server, 30/128 oracle), which keeps such a name out of trees — and out of the drop statement — altogether.

---

suggestion (non-blocking): Of the six forLog() call sites, only the "no table of this backend" description (:5632, the v column) is driven by a test that puts a control character through it.

opendj-server-legacy/src/main/java/org/opends/server/backends/jdbc/JDBCStorage.java:5597, :5610, :5631, :2941, :3083, :3087, :3091
opendj-server-legacy/src/test/java/org/opends/server/backends/jdbc/ClearReportTestCase.java:175

No test writes a k value — recordAnotherTable (TestCase.java:2921) and emptyTheRecordedTableNames (:2931) update v only, every key comes from the storage's own openTree — so the two key-side descriptions and the tree name at :2941 never see a control character; no test stamps a table with a comment other than stale (:1161, :1229), so leftovers.ours (:3364, parsed by the lax TreeName.valueOf, checked by isOwnTree on base DN only) never carries one into :3083. ClearReportTestCase:175 escapes its own descriptions before handing them to reportSkippedRows(), so it re-pins forLog() (already pinned at :77-98) and the constant text, not the wiring. Deleting forLog() at any of the five other sites leaves 7/7 and 82/82 green (by reading, not measured). The roads are reachable: TreeName.valueOf accepts any string with a / at index 0 and another at index ≥ 2.

// TestCase.java — a second real-clear case: the newline in the key, the table not there
final byte[] key = ("/" + baseDn + "/tree\nSEVERE: spliced").getBytes(UTF_8);
insertCatalogRow(con, key, "opendj_nosuchtable");   // v passes isOwnTableName, isExistsTable says no
clearAndCollect();
for (final String line : storage.lines) {
	assertFalse(line.indexOf('\n') >= 0 || line.indexOf('\r') >= 0, "a report line was split by the key it carries: " + line);
}

Pin: one case per road — a key of no-slash\nSEVERE for :5610, the key above for :2941, and writeTableComment(con, table, "/" + baseDn + "/x\nSEVERE") on a leftover table before the clear for :3083; or the per-site table of forLog()-deleted mutants against ClearReportTestCase + PgSqlTestCase.

---

suggestion (non-blocking): The per-row warn gates of readCatalogRows() and its end-of-read summary warn are pinned by no test.

opendj-server-legacy/src/main/java/org/opends/server/backends/jdbc/JDBCStorage.java:5599, :5611, :5633, :5647-5649
opendj-server-legacy/src/test/java/org/opends/server/backends/jdbc/ClearReportTestCase.java:153

The three gates and the summary go to logger.warn only; ReportingStorage (TestCase.java:2962) captures reportClearLine alone, and no jdbc test captures the error log. ClearReportTestCase:153 pins add()'s boolean for 100 rows, not that the caller consults it; the two real-clear cases put one foreign row each through the read, so size() never passes 20 and :5647 never fires. Dropping the if around any warn, or deleting :5647-5649, stays green (by reading, not measured). Half of the description's problem statement — "a million logger.warn records on the way in" — is bounded by code nothing holds to.

// ClearReportTestCase — no database needed: readCatalogRows(Connection, String, SkippedRows) wants a ResultSet
final Connection con = mockConnectionReturning(rowsOf(MAX_REPORTED_VALUES + 1, "not-a-tree-name", "opendj_x"));
final SkippedRows skipped = new SkippedRows();
final List<String> warned = captureWarns(() -> storage.readCatalogRows(con, "opendj_catalog", skipped));
assertEquals(warned.stream().filter(w -> w.contains("not the name of a tree")).count(), MAX_REPORTED_VALUES);
assertEquals(warned.stream().filter(w -> w.contains("the first " + MAX_REPORTED_VALUES + " are named above")).count(), 1);

Pin: the mocked ResultSet road above with a counting log publisher registered for the case, or a container case seeding MAX_REPORTED_VALUES + 1 foreign rows under the same capture.

---

suggestion (non-blocking): testForLogBoundsHowMuchOfAValueALineCarries feeds a uniform value, so it pins how much is kept and not which part.

opendj-server-legacy/src/test/java/org/opends/server/backends/jdbc/ClearReportTestCase.java:106-109

5000 identical 'x' make every 200-unit substring equal: a forLog() keeping the last 200 (loop from length - kept), or every other unit, renders the same string and stays green; every other forLog(String) input in src/test is shorter than the cap, so prefix and suffix coincide there too. An operator recognises a value by its head, and nothing says the head is what the line shows.

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.startsWith(huge.substring(0, JDBCStorage.MAX_LOGGED_VALUE_LENGTH)), "the line does not show the head of the value: " + escaped);

---

suggestion (non-blocking): forLog(String) cuts at MAX_LOGGED_VALUE_LENGTH UTF-16 units, so a supplementary character straddling index 199/200 leaves a lone high surrogate at the end of the kept text.

opendj-server-legacy/src/main/java/org/opends/server/backends/jdbc/JDBCStorage.java:3169-3172

A k value decoded by new String(db2real(key), UTF_8) (:5607) from a 4-byte sequence is a surrogate pair; with the high surrogate at 199 and the low at 200, kept = 200 keeps the high one alone. Character.isISOControl is false for it and it is not U+2028/U+2029, so it is appended verbatim before the ...(+N more characters) tail, and the log encoder writes U+FFFD or ? for it. Cosmetic: a surrogate ends no record, nothing throws, the count is in code units.

int kept = Math.min(value.length(), MAX_LOGGED_VALUE_LENGTH);
if (kept < value.length() && Character.isHighSurrogate(value.charAt(kept - 1))) {
	kept--;   // never cut a pair in half; the tail counts the unit given back
}

---

note (non-blocking): Not checked.

• NC-1-3 — whether CI discovers ClearReportTestCase (a bare DirectoryServerTestCase subclass, no @BeforeClass startServer) and whether the ubuntu cells ran the container suites for the new real-clear case (the description ran PgSqlTestCase locally only). All five build-maven (ubuntu-latest, *) cells are green on 181e678; the job log itself could not be fetched during this round (api.github.com TLS handshake timeouts). Closes on a -- Executing test: ClearReportTestCase line, and the Tests run lines of the four container suites, in one ubuntu job log.
• NC-1-5 — whether a >63-character opendj… name through isExistsTable()/getTables() (:2935) on postgresql can match a truncated existing table: pre-existing at BASE (isOwnTableName() is #893's), outside this PR's lines, needs a postgres container; recorded, not run.

[vharseko]

@maximthomas thank you - all six taken, and the first of them further than it was asked to go. Round 2 is 86bb2b5.

S1 - the recorded name on the "whose table is not there" line

Taken, and you were right that the description offered it. :2941 puts both values through forLog() now:

config.getBackendId(), forLog(tree.getKey().toString()), forLog(tableName)));

And the number of those lines is unbounded in the same way, which the description had wrong. It called them "one line per row of a catalog this backend wrote itself"; they are not. A row reaches that line by recording a name of this backend's namespace that no table goes by, and a foreign writer makes as many of those as it likes - each one a reportClearLine(), which is a logger.warn. So the same cap bounds how many of them are named, with one line where it cuts in:

if (missingRows>MAX_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));
}

counts.missingTrees goes on counting every such row, so nothing an operator counts by changed - what the cap takes away is the naming, exactly as for the other lists.

The alternative you offered - a length bound in isOwnTableName() - is not folded in here, and gets an issue of its own instead. It is a different question from what a log record may carry: it decides what the drop path admits, it is #893's rule rather than this PR's lines, and it moves such a row from "a tree whose table is not there" to "a row passed over", which changes what a clear reports. NC-1-5 goes into that issue with it, a length bound being what would close it.

S2 - five of the six call sites driven by no test

Right, and the table below is measured rather than read. The three lists of reportClearOutcome() are pinned without a database - leftoverTables() is a method of the storage, so the case hands the lists in rather than asking a schema for them, which is also the only way to get a stamp somebody else wrote into one. The two key-side roads are real clears off a new insertCatalogRow() helper: nothing this backend writes puts a key of somebody else's choosing into a catalog, so the case writes the row itself.

call site	what drives it	mutant: forLog() taken out
:5610 the key of a row naming no tree	testAClearDoesNotLetACatalogKeyThatNamesNoTreeEndTheLineReportingIt	red - "the row whose key names no tree was reported by no line of the clear"
:5631 / :5632 the tree name and the recorded name of a foreign row	testAClearDoesNotLetACatalogRowEndTheLineReportingIt (round 1)	red in round 1
:2941 the tree name of a missing table	testAClearDoesNotLetTheRowOfAMissingTableEndTheLineReportingIt	red - "the row naming a tree whose table is not there was reported by no line"
:2941 the recorded name	the same case, by the length cap: isOwnTableName() forbids the control characters, so what shows there is a 260 character name	red - "the whole of a 260 character name recorded by a row reached the line carrying it"
:3083 / :3087 / :3091 the three leftover lists	testTheListsOfWhatAClearLeftStandingAreBoundedAndCarryNoControlCharacter	red, one per list - "a line of the report can be split in two by a value it carries"

The new cap on how many such lines a clear names is pinned by testAClearBoundsHowManyRowsOfAMissingTableItNames, and the mutant taking the cap out is red ("a line was reported for every row whose table was not there").

S3 - the per-row warn gates and the end-of-read line

Taken, through a real read rather than a mocked ResultSet: readCatalogRows() goes through executeResultSet() and its bound, and a container is cheaper than standing that up. testAReadOfACatalogBoundsTheWarningsItWritesPerRow seeds MAX_REPORTED_VALUES + 1 rows whose keys name no tree and reads the error log of the run back. Both mutants are red: the gate dropped ("a warning was written for every row the read passed over") and :5647-5649 deleted ("the read did not say once how many rows it passed over without a line of their own").

One thing worth writing down for the next case that reads that log: it holds every record twice, one copy per publisher registered for a test run, so the assertions count the records that differ.

S4 - a uniform value pins how much and not which part

Taken as written: the value is a..z repeating and the case asserts the head. The mutant keeping the tail instead is red.

S5 - a surrogate pair cut in half

Taken:

int kept=Math.min(value.length(), MAX_LOGGED_VALUE_LENGTH);
if (kept<value.length() && Character.isHighSurrogate(value.charAt(kept-1))) {
	kept--;
}

The unit given back is counted by the tail like any other. testForLogDoesNotCutASupplementaryCharacterInHalf puts a pair across the cap and walks the result for a surrogate standing on its own; without the guard it is red at index 199.

NC-1-3 - what CI ran

Answered from the job log, which came back this time - run 34564104369, job 103393357285, build-maven (ubuntu-latest, 26) on 181e678f:

• ClearReportTestCase is discovered (**/*TestCase.java is one of the failsafe includes, opendj-server-legacy/pom.xml:1249) and ran green: Tests run: 7, Failures: 0, Errors: 0, Skipped: 0.
• testAClearDoesNotLetACatalogRowEndTheLineReportingIt ran in all four container suites of that one job: MsSqlTestCase 81/0, MySqlTestCase 81/0, OracleTestCase 81/0 (1 skipped), PgSqlTestCase 82/0.

So the offer in the description to run the other three engines is already answered by CI, and this round's four new container cases are run the same way.

Tests of this round

suite	where	result
ClearReportTestCase	locally	9/9
PgSqlTestCase	locally, against a container	86/86, Skipped: 0
11 mutants	locally	all red, each killed by the assertion named above and by no other

MySqlTestCase, MsSqlTestCase and OracleTestCase were not run locally for the same reason as in round 1 - nothing here is engine-specific - and all four new cases run in every one of them.