Schema changes cost 20 to 100 ms each on disk (10 to 40 times tmpfs): about 150 ms per type with one property and one index

[tae898]

Context

Creating a schema on disk costs about 150 ms per type with one property and one index, against 5 to 9 ms on tmpfs, so an application with 100 indexed types spends about 15 s creating its schema, and a test suite that builds a fresh database per test pays it on every test. Batching the same statements into one transaction brings it to 42 to 47 ms per type, still five to eight times tmpfs. Found while measuring #8626: its repro took 15 s to create 100 indexed types.

Repro (Java, below)

DdlCost.java: 30 rounds of createDocumentType + createProperty + createTypeIndex (LSM, NOTUNIQUE), each statement timed on its own, then the same through SQL, then 30 more types with all three statements inside one begin() / commit(). Laptop NVMe, 4 cores, 7bb0c116f9 (today's snapshot, with #8630), Temurin 25 with compact object headers / Temurin 21, p50 after 2 warm-up rounds:

statement	on disk	on tmpfs	files it creates
createDocumentType / CREATE DOCUMENT TYPE	94 to 105 / 97 ms	4 to 6 ms	one bucket file
createProperty / CREATE PROPERTY	18 to 20 / 20 ms	0.5 to 1 ms	none
createTypeIndex / CREATE INDEX	40 to 43 / 42 to 44 ms	3 to 5 ms	one index file
all three for 30 types in one transaction	42 to 47 ms per type	5.5 to 9 ms per type	same files

The API and SQL are the same within noise, and de966e79c5 (before #8630) measures the same (96 ms per CREATE DOCUMENT TYPE, 42 ms per type batched), so #8630 did not change it.

Where it comes from, as far as I can read it

LocalSchema.saveConfiguration() rewrites the whole schema on every change: update() copies schema.json to schema.prev.json and writes the new one, each an atomic write that, since #7465, also fsyncs the directory. That durability is right, and CREATE PROPERTY, which creates no file, shows its price: about 19 ms per statement on this drive. saveConfiguration() already postpones the write while a transaction is active, which is why the batched form saves most of it. What remains per type in the batch (about 40 ms) is creating the bucket and index files, which is 20 to 50 times what the same creation costs on tmpfs.

Questions

1. Is wrapping schema setup in one transaction the recommended way to create many types, and is DDL inside a transaction supported as a contract (it works here: the types and indexes exist after commit)? If so, it would be worth a line in the docs; we will recommend it in our Python bindings either way.
2. Could the schema save be deferred to the end of a multi-statement SQL script too (sqlscript of CREATE ... statements), the way the internal multipleUpdate flag defers it inside one operation?
3. Where do the ~40 ms per new bucket or index file go on disk (preallocating pages, a full fsync plus a directory fsync per file)? Creating a type's single bucket costs more than writing the whole schema.

DdlCost.java

import com.arcadedb.database.*;
import com.arcadedb.schema.*;
import java.util.*;

/**
 * Schema changes one at a time, each timed on its own: createDocumentType, createProperty, createTypeIndex, and
 * the same three through SQL. N rounds per statement kind, median and p90. Nothing else runs.
 *
 *   java DdlCost <dbDir> <rounds>
 */
public class DdlCost {
  public static void main(String[] a) {
    int rounds = Integer.parseInt(a[1]);
    System.out.println("engine " + com.arcadedb.Constants.getRawVersion() + " " + com.arcadedb.Constants.getBuildNumber()
        + ", java " + System.getProperty("java.version") + ", dir " + a[0]);
    try (DatabaseFactory f = new DatabaseFactory(a[0] + "/ddl")) {
      if (f.exists()) f.open().drop();
      try (Database db = f.create()) {
        List<Double> type = new ArrayList<>(), prop = new ArrayList<>(), idx = new ArrayList<>();
        List<Double> sqlType = new ArrayList<>(), sqlProp = new ArrayList<>(), sqlIdx = new ArrayList<>();
        for (int i = 0; i < rounds; i++) {
          long t0 = System.nanoTime();
          DocumentType t = db.getSchema().createDocumentType("A" + i);
          long t1 = System.nanoTime();
          t.createProperty("k", Type.LONG);
          long t2 = System.nanoTime();
          db.getSchema().createTypeIndex(Schema.INDEX_TYPE.LSM_TREE, false, "A" + i, "k");
          long t3 = System.nanoTime();
          type.add((t1 - t0) / 1e6); prop.add((t2 - t1) / 1e6); idx.add((t3 - t2) / 1e6);
        }
        for (int i = 0; i < rounds; i++) {
          long t0 = System.nanoTime();
          db.command("sql", "CREATE DOCUMENT TYPE B" + i);
          long t1 = System.nanoTime();
          db.command("sql", "CREATE PROPERTY B" + i + ".k LONG");
          long t2 = System.nanoTime();
          db.command("sql", "CREATE INDEX ON B" + i + " (k) NOTUNIQUE");
          long t3 = System.nanoTime();
          sqlType.add((t1 - t0) / 1e6); sqlProp.add((t2 - t1) / 1e6); sqlIdx.add((t3 - t2) / 1e6);
        }
        // The same three statements for `rounds` more types, all inside ONE transaction: saveConfiguration() postpones
        // the schema write while a transaction is active, so if DDL is allowed here the file is written once.
        String batch = "ok";
        long b0 = System.nanoTime();
        try {
          db.begin();
          for (int i = 0; i < rounds; i++) {
            DocumentType t = db.getSchema().createDocumentType("C" + i);
            t.createProperty("k", Type.LONG);
            db.getSchema().createTypeIndex(Schema.INDEX_TYPE.LSM_TREE, false, "C" + i, "k");
          }
          db.commit();
        } catch (Exception e) {
          batch = e.getClass().getSimpleName() + ": " + e.getMessage();
          if (db.isTransactionActive()) db.rollback();
        }
        long b1 = System.nanoTime();
        System.out.printf("RESULT batched in one transaction: %d types+property+index in %.1f ms (%.2f ms per type), %s%n",
            rounds, (b1 - b0) / 1e6, (b1 - b0) / 1e6 / rounds, batch);
        System.out.printf("RESULT types in schema after: %d, C0 has index: %s%n", db.getSchema().getTypes().size(),
            db.getSchema().existsType("C0") && !db.getSchema().getType("C0").getAllIndexes(false).isEmpty());
        print("API createDocumentType", type); print("API createProperty", prop); print("API createTypeIndex", idx);
        print("SQL CREATE DOCUMENT TYPE", sqlType); print("SQL CREATE PROPERTY", sqlProp); print("SQL CREATE INDEX", sqlIdx);
        System.out.printf("RESULT schema files: %s%n", Arrays.toString(new java.io.File(a[0] + "/ddl").list((d, n) -> n.startsWith("schema"))));
      }
    }
  }

  static void print(String what, List<Double> v) {
    List<Double> s = new ArrayList<>(v.subList(Math.min(2, v.size()), v.size()));
    Collections.sort(s);
    System.out.printf("RESULT %-26s p50 %7.2f ms  p90 %7.2f ms  (n=%d after 2 warm-up)%n", what, s.get(s.size() / 2),
        s.get((int) (s.size() * 0.9)), s.size());
  }
}

run.sh (extracts the image's jars, runs in a Temurin container, on a bind-mounted directory and on tmpfs)

#!/usr/bin/env bash
# run.sh [image] [jdk] [cpus]: DdlCost on disk (a bind mount under ~/build-scratch) and on tmpfs, same container.
set -e
IMG=${1:-arcadedata/arcadedb:26.10.1-SNAPSHOT}; JDK=${2:-25}; CPUS=${3:-0-3}
cd "$(dirname "$0")"; W=~/build-scratch/ddl-cost; rm -rf lib cls "$W"; mkdir -p lib cls "$W"
cid=$(docker create "$IMG"); docker cp "$cid:/home/arcadedb/lib/." lib/ >/dev/null; docker rm "$cid" >/dev/null
echo "image $IMG $(unzip -p lib/arcadedb-engine-*.jar com/arcadedb/arcadedb.properties | grep buildNumber) jdk $JDK cpus $CPUS"
RUN="docker run --rm --user $(id -u):$(id -g) --cpuset-cpus $CPUS -m 6g -e HOME=/w -v $PWD:/w -v $W:/disk --tmpfs /ram:rw,size=3g,uid=$(id -u) -w /w eclipse-temurin:$JDK-jdk"
$RUN javac -nowarn -cp '/w/lib/*' -d /w/cls DdlCost.java 2>&1 | grep -v '^Note' || true
EXTRA=""; [ "$JDK" = 25 ] && EXTRA="-XX:+UseCompactObjectHeaders"
for d in /disk /ram; do
  $RUN java -Xmx2g $EXTRA --add-modules=jdk.incubator.vector --enable-native-access=ALL-UNNAMED -cp '/w/lib/*:/w/cls' DdlCost $d ${ROUNDS:-30} 2>&1 | grep -oE 'engine .*|RESULT.*|[A-Za-z.]*Exception.*'
done
rm -rf lib cls "$W"