Performance of an openEHR CDR based on a graph database

Implementation Platform
,
1

@erik.sundvall just posted another great opportunity to join their team to build a new openEHR CDR (Join or comment CDR Catalyst initiative from Karolinska - #5 by erik.sundvall).

His Catalyst posts and document piqued my interest, so about two months ago I selected one of the databases mentioned in the Catalyst document and started building an openEHR CDR from scratch.

After 2 months my “Catalyst CDR” is working. I implemented the latest EHR REST API 1.1.0 and have started running benchmarks against EHRbase.

The first test involves creating 100 EHRs, each with 1000 compositions. I’m using an 885-line Vital signs composition to make the test realistic (total time in mm:ss | time per composition):

   Total mm:ss | per composition
-------------- | ---------------
EHRbase: 16:02 | 9,62 ms
ArcEHR :  9:32 | 5,73 ms

The second test is querying the compositions using all 7 different ways to use the GET COMPOSITION endpoints (700k queries):

   Total mm:ss | per query
-------------- | ---------
EHRbase: 30:55 | 26,50 ms (edit: fixed the calculation)
ArcEHR : 10:12 |  6,12 ms

I’m running this on my 5 year old Apple M1 Pro with 16 GB RAM, while simultaneously running 3 IDEs and Docker.

These results are a good sign that the Karolinska team can be confident a performant CDR can be built using a graph database. I can’t wait to see which database they pick.

The side effect of picking ArcadeDB for my CDR is support for different querying languages (SQL, Cypher, Gremlin, GraphQL, MongoDB QL, GQL). Since AQL is missing, I started implementing it in ArcEHR so that I can benchmark querying performance using AQL.

I’m a bit disappointed that after asking for open source CDRs in their procurements, they decided to make Catalyst a closed-source project. I still hope to publish ArcEHR as an Apache 2.0 licensed openEHR CDR (let me know if you are interested in contributing to this effort).

2

The querying performance felt incorrect, so I investigated further and found a bug in ArcadeDB. They fixed it (overnight!) and the new results are:

   Total mm:ss | per query
-------------- | ---------
EHRbase: 30:55 | 2,650 ms (edit: fixed the calculation)
ArcEHR :  4:31 | 0,272 ms (edit: fixed the calculation)

Edit:
The results for committing compositions also improved:

   Total mm:ss | per composition
-------------- | ---------------
EHRbase: 16:02 | 9,62 ms
ArcEHR :  7:22 | 4,43 ms
3

They obviously felt bad about that bug :wink:

4

The bug was only in the “fluent query builder”. Executing raw SQL worked properly.

They fix and improve everything so fast. It looks like the team has members in the EU and the US. This means they never sleep.

5

In addition to that I really like the ArcadeDB licencing and business model too.

6

A new CDR was just announced by @rubentalstra so I ran my performance tests on it.

The results for committing 100k compositions:

    Total mm:ss | per composition
--------------- | ---------------
EHRbase : 16:02 | 9,62 ms
FerroEHR: 11:42 | 7,02 ms
ArcEHR  :  7:22 | 4,43 ms

The second test queries the created compositions using all 7 different ways to use the GET COMPOSITION endpoints (700k queries):

    Total mm:ss | per query
--------------- | ---------
EHRbase : 30:55 | 26,50 ms
FerroEHR: 28:29 | 24,42 ms
ArcEHR  :  4:31 |  2,72 ms
7

can you maybe share you test logic?

because I have stress tested FerroEHR and I can do 512 request/s, (30.720 a minute) on an 5mb payload. if you have maybe seen the stress test page?

8

I’ve read through your performance page but it is AI;DR :wink:

I like my tests simple. I have attached the tests I’m using.

The write test loops from 1 to 100, creating 100 EHRs. For each EHR, it creates 1000 compositions using the attached Vital signs instance. This results in 100k compositions.

The read test consists of 7 GET endpoints in the REST API. This results in 700k queries.

Docker is restarted between the write and read tests to clear any caches.

Vital signs-cabolabs.json (22.1 KB)

src.zip (22.2 KB)

9

thank you!

I will have a look straight away and maybe recursive loop somewhere that you have found.

I will get back to you for sure. thank you already for testing it :slight_smile:

10

@borut.jures

The problem turned out to be self-inflicted: FerroEHR stores each composition split into ~60 rows (that layout is what makes AQL fast, CONTAINS is just an integer interval join), but every GET was fetching all those rows back and rebuilding the JSON from them, plus a second round trip, plus a retry against archive storage on every miss. PostgreSQL itself was doing under 0.1 ms of actual work per read, the rest was overhead I added around it.

So I changed the storage: the canonical JSON is now also written once at commit (vo_version.body), and a GET is a single SQL statement reading that column. The node rows stay as the AQL index. Same treatment for the other reads (EHR_STATUS, directory, versioned objects, revision history, the 404 path), AQL whole-object queries now serve the stored body directly, and compression runs at the fastest level.

Numbers on my machine (Macbook air M2-series, PG18 in Docker, your composition, single client, keep-alive). These only compare against themselves, not against your hardware:

your run of 4.0.1 develop, my machine
GET COMPOSITION, average of the 7 endpoints 24.42 ms ~1.0 ms
composition GET (latest) 0.93 ms
versioned_composition / revision_history 0.38 / 0.41 ms
VERSION reads 1.3–1.8 ms
commit (durable, audit + signing on) 7.02 ms ~7.6 ms p50, unchanged

Currently working on fixing the commit. The 7.6 ms is mostly WAL fsync plus index maintenance on the node rows, so there is room :wink: .

All of this runs with ATNA auditing and version signing on by default. That means that for every action it inserts a database record for auditing purposes and also checks and validates signatures as well.

This new fix is on the develop branch right now, v4.0.2 should ship soon (today or tomorrow).

11

well that’s interesting - do the times include the ATNA updates?

@borut.jures have you got an ATNA service running?

The race is on :wink:

12

oh yes for sure: Audit trail (IHE ATNA) - FerroEHR Documentation

ATNA is always on by default so all request read or write are logged by default so the insert of database records are included by default in it.

13

I had to google it :wink:
I only implemented change control found in the specifications. That covers AUDIT_DETAILS.

@rubentalstra I’ve seen the commits mention signing and wanted to ask about that. Your documentation link answers my question.

14

I rerun the tests on my machine but Docker is still using v4.0.1. so I was testing the old version.

Based on your results, we will get a new winner tomorrow :wink:

Let’s hope the EHRbase team joins “the race”. They have actual users who would appreciate it. @rubentalstra showed what is possible in just a few hours.

15

v4.0.2 is out now:

your harness metric your run of 4.0.1 4.0.2, my machine
create, per composition (100k) 7.02 ms 5.56 ms
read, per query (700k) 24.42 ms 1.69 ms

Audit trails and version signing were on for the whole run, as they are by default.

The commit still has room: about 3 ms of it is btree index maintenance on the ~65 rows each composition decomposes into, plus WAL fsync. That’s next on the list.

Curious what your machine says.

16

@rubentalstra I like that you care about the performance of your solution. But you don’t have to stay up until 3 in the morning :wink:

I’m currently optimizing my code too. Can you please run the tests on your machine for version 4.0.1 before the improvements to compare it to 4.0.2 on your machine.

Please also run the tests on EHRbase to get the relative speed factor of your machine compared to mine.

17

I optimized my code, but I prefer when properties in returned instances are sorted in the same order as the properties in RM. This adds some processing time, but I believe it is worthwhile.

I noticed your latest changes resulted in returning instances with unsorted RM properties. If you ask Fable to check the specifications, you will find that this is not required. It is a matter of taste :wink:

I switched to µs for the read times and reran tests for all three solutions.

The results for committing 100k compositions:

    Total mm:ss | per composition
--------------- | ---------------
EHRbase : 15:51 | 9,52 ms
FerroEHR: 10:16 | 6,16 ms
ArcEHR  :  7:22 | 4,43 ms

The second test queries the created compositions using all 7 different ways to use the GET COMPOSITION endpoints (700k queries):

    Total mm:ss | per query
--------------- | ---------
EHRbase : 30:55 | 2651,00 μs
FerroEHR: 24:11 | 2073,70 μs
ArcEHR  :  3:05 |  264,77 μs

It is interesting that I changed less than 10 lines of code while Fable changed thousands of lines. I hope the AI approach doesn’t degrade code quality over time :thinking:

I’ve noticed remarks in your commits about the time your database spends. If it makes you feel better, my database consumes 68% of all time for the read test and 69% for the write test.

18

@borut.jures

I ran your test suite on my machine for the three FerroEHR versions and EHRbase, so you can compute the relative speed factor between our machines from the EHRbase row.

Setup, so the numbers are comparable: every run used the same protocol — a fresh database volume per run (no reuse between versions; each FerroEHR version applies its own schema on boot), the same PostgreSQL 18.6 image for all FerroEHR runs, EHRbase 2.35.1 with its own ehrbase-v2-postgres:16.2 image, all via Docker Compose on the same idle machine (Apple Silicon, Docker Desktop). Create phase = your 100 EHRs x 1,000 compositions (100,000 creates of the Vital signs composition, ~65 nodes); read phase = your 700,000 read/query mix over that data. FerroEHR ran with its defaults: audit logging on (IHE ATNA), version signing on (SHA-256 digest, re-verified on every read), strict validation on.

CDR create (avg per composition) read (avg per query) server memory under load
FerroEHR 4.0.1 5.28 ms 1.46 ms —
FerroEHR 4.0.2 4.77 ms 1.30 ms —
FerroEHR develop (next release) 3.97 ms 1.17 ms 51 MiB
FerroEHR develop, audit + signing off 3.13 ms 942.09 μs 48 MiB
EHRbase 2.35.1 8.70 ms 1.66 ms 704 MiB

The audit + signing off row is only there to show the cost of the compliance features (~0.8 ms per commit, and reads stop re-verifying the signature). FerroEHR ships with both on and the defaults-on row is the number we publish. One footnote from that run: with signing off, the read mix got fast enough to trip FerroEHR’s default per-principal rate limiter (1024 req/s), so that lane ran with the limiter disabled.

19

@rubentalstra Based on FerroEHR 4.0.2 vs EHRbase, the factor for write tests is 1,82389937. Based on my computer, the factor between them is 1,54545455.

For the read tests, your factor is 1,27692308, while mine is 1,27839128.

The read factors are “the same”. We might figure out why the write factors differ in future tests.

Using the read factor to account for the difference in our computers’ speeds, FerroEHR’s write speed is effectively the same in our measurements.

Using the same read factor on EHRbase write results, I get 11,12 ms per created composition (this matches my average test time; I reported the fastest time seen in the above tables).

I conclude that we can use 1,27839128 as the speed difference factor for both read and write results.

Can you get your read speed under 1 ms?

20

It would be fun to run this on Atomik too @borut.jures :slight_smile: