Skip to content

Startup existence checks use count(*) on inode — ~148ms each, 88% of startup time when init retries #36865

Description

@dsolistorres

Description

Two run-always startup tasks decide "is this database populated?" by counting every row in inode, then discarding the count:

// Task00001LoadSchema.java:102-104 — direct pool borrow
try (Connection conn = DbConnectionFactory.getDataSource().getConnection();
     Statement stmt = conn.createStatement();
     ResultSet rs = stmt.executeQuery("select count(*) as test from inode")) {
    rs.next();
    return false;
// Task00004LoadStarter.java:21-23
db.setSQL("select count(*) as test from inode");
int test = db.getInt("test");
return (test < 1);
// DotCMSInitDb.java:44 — same pattern in isConfigured()
return new DotConnect().setSQL("select count(*) as test from inode").getInt("test") > 0;

All three need only existence, never cardinality. On Postgres, count(*) on a large inode table is a full scan or full index scan — measured at ~148ms on the production table in the spike #36544 incident. EXISTS / SELECT 1 … LIMIT 1 stops at the first row.

Why this is not the negligible cleanup it looks like. StartupTasksExecutor.executeStartUpTasks() invokes forceRun() on all nine run-always tasks every time it is called, with no already-ran guard (StartupTasksExecutor.java:185-191). And MainServlet.init() (:129) — which calls it — throws DotRuntimeException on failure, so Tomcat re-instantiates and re-inits the servlet on the next request.

During the #36544 incident that produced:

select count(*) as test from inode executions in one 600s window 3,571
Mean per execution ~148ms
Total 528s ≈ 88% of the startup window
Implied MainServlet.init() attempts ~1,786 (2 executions per pass on a populated DB)

So in the pathological case these three call sites dominate startup time. Converting them to existence checks would reduce that 528s to a few seconds — it does not fix the crash-loop itself (see #36801, #36802, #36803), but it removes the single largest time sink that made startup unable to converge.

Task00001LoadSchema.forceRun() additionally takes its own dedicated pool borrow on every pass (deliberately, per its comment, to avoid poisoning the outer transaction), so each pass also costs a pool acquisition.

This issue supersedes the original "no-go" recommendation on the conditional follow-up in spike #36544's AC #7. That recommendation assumed these sites run once per startup; it held the startup count fixed while the incident consisted of startup repeating. See the correction on #36544.

Acceptance Criteria

  • Task00001LoadSchema.forceRun() (:102-104) uses an existence check rather than count(*). Its current contract must be preserved exactly: it returns false when the query succeeds and true when it throws SQLException (an absent inode table meaning an empty/unschema'd DB) — the exception is the signal, so the replacement query must still fail the same way on a missing table.
  • Task00004LoadStarter.forceRun() (:21-23) uses an existence check; behaviour for an empty-but-existing inode table (currently test < 1true) is unchanged.
  • DotCMSInitDb.isConfigured() (:44) uses an existence check; behaviour unchanged (> 0 → populated).
  • The chosen form is portable across the supported database(s) — prefer SELECT 1 FROM inode LIMIT 1 or SELECT EXISTS (SELECT 1 FROM inode) over vendor-specific syntax.
  • Verified on a large inode table that per-execution time drops from ~148ms to single-digit ms, via pg_stat_statements or EXPLAIN ANALYZE.
  • Verified that a fresh, empty database still bootstraps correctly end to end — this is the risk surface: these three checks gate schema load and starter import, so a behaviour change here breaks first-boot. Cover both "no inode table at all" and "inode table present but empty".
  • Verified that an existing populated database still starts normally and does not re-run the starter import.

Priority

Medium

Additional Context

How to measure it

  1. Point dotCMS at a database with a large inode table (the incident environment; any sizeable production clone will do).
  2. Enable statement timing:
CREATE EXTENSION IF NOT EXISTS pg_stat_statements;
  1. Start dotCMS and let startup complete, then measure the baseline:
SELECT calls, round(mean_exec_time::numeric,1) AS ms_avg,
       round(total_exec_time::numeric/1000,1) AS s_total
  FROM pg_stat_statements WHERE query ILIKE '%as test from inode%';

Two executions per successful startup, each proportional to inode size.

  1. To observe the pathological multiplier, use the spike harness which drives repeated init failures — docker/docker-compose-examples/pubsub-connection-churn/ on branch issue-36544-pubsub-connection-churn-spike. The calls count climbs 2 per MainServlet.init() attempt.

Compare against EXPLAIN ANALYZE for the two forms:

EXPLAIN ANALYZE SELECT count(*) AS test FROM inode;
EXPLAIN ANALYZE SELECT 1 FROM inode LIMIT 1;

Version

Present on main. Measured during the #36544 incident on 26.07.06-01 (commit 5efb47a). The call sites are long-standing and not specific to any recent change.

Links

Metadata

Metadata

Assignees

Type

Projects

Status
Done

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions