Skip to content

EmbeddedDatabase#drop 30x latency regression between 23.5.1 and 23.6.1 #1234

Description

@erickj

ArcadeDB Version:

upgrading from 23.5.1 to 23.6.1

OS and JDK Version:

$ java -version
openjdk version "17.0.7" 2023-04-18
OpenJDK Runtime Environment (Red_Hat-17.0.7.0.7-4.fc37) (build 17.0.7+7)
OpenJDK 64-Bit Server VM (Red_Hat-17.0.7.0.7-4.fc37) (build 17.0.7+7, mixed mode, sharing)

$ cat /etc/os-release 
NAME="Fedora Linux"
VERSION="37 (Server Edition)"

Expected behavior

Upgrading from 23.5.1 to 23.6.1 should not have regressed Database#drop

screenshot of "slow" 23.6.1 profile showing 904 ms spent in EmbeddedDatabase#drop, w/ 872 ms coming from PageManager#close:
Screenshot from 2023-09-09 19-50-55

screenshot of "fast" 23.5.1 profile showing 36 ms spent in EmbeddedDatabase#drop:
Screenshot from 2023-09-09 19-46-59

The only difference between these profiler snapshots is the arcadedb upgrade

Actual behavior

Between upgrading from 23.5.1 to 23.6.1 a single test I have went from executing in ~6 seconds to >24 seconds

faster 23.5.1 test logs show:

5300 [main] [INFO] io.vos.service.graph.database.arcadedb.ArcadeUpsertNodeMutationTest - dropping db:[/tmp/arcadedb-databases/ArcadeUpsertNodeMutationTest-285f7f28-ca71-4f1b-9bf0-ca3b2161cc54]
| | | | | | |  duration: 30 ms
| | | | | | |    status: [OK] SUCCESSFUL
| | | | | '-- VertexTests finished after 93 ms.
| | | | '-- UpsertNodeMutationTests finished after 5337 ms.

slow 23.6.1 test logs show:

23265 [main] [INFO] io.vos.service.graph.database.arcadedb.ArcadeUpsertNodeMutationTest - dropping db:[/tmp/arcadedb-databases/ArcadeUpsertNodeMutationTest-fad9eea7-ed02-4ae0-9b1f-690f1fc203d0]
| | | | | | |  duration: 1031 ms
| | | | | | |    status: [OK] SUCCESSFUL
| | | | | '-- VertexTests finished after 3094 ms.
| | | | '-- UpsertNodeMutationTests finished after 24298 ms.

From the above "dropping db" log line, there is a slow down from ~30ms to ~1s per test, where "teardown" is effectively:

    logger.info("dropping db:[{}]", dbName);
    if (db != null) {
      db.drop();
      db = null;
    }

I have been unable to reproduce this regression on the arcadedb test suites, trying to use com.arcadedb.DocumentTest as a proxy for teardown behavior, but it's 100% repeatable in my test setup.

Profiling the running tests with VisualVM shows the latency regression is 100% located in com.arcadedb.engine.PageManager#close

Steps to reproduce

I'm still working on a simply JUnit test that reproduces the issue, but I"m filing a bug here in case it's obvious where the regression might have come from in the release window.

Metadata

Metadata

Assignees

Type

No type
No fields configured for issues without a type.

Projects

No projects

Milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions