Docker Container Example : Strabon and Virtuoso against the Synthetic Workload

By Theofilos Ioannidis (tioannid [at] di [dot] uoa [dot] gr), created on , last updated on


Caution

Containers are not ideal for benchmarking purposes similar to the one GeoRDFBench Framework performs, because they do not allow clearing system caches. The reason for this is that:

Therefore, in the following example, although the user can verify that the experiments run properly and results are correctly calculated and reported, the COLD cache response times will not be accurate. However, for experiments that do not require COLD cache response time measurements, e.g., macro benchmark scenarios, response times should be accurate enough for drawing basic conclusions.

Key Features

This example, features:

Docker Image

For this example, we will use an Ubuntu 22.04 (jammy) host machine, with 32 GB of DDR4-2400MHz memory, an Intel i7-7700 CPU (8 executing threads=4 cores * 2 threads/core), a Samsung SSD NVMe 970 EVO Plus 500GB system disk and a 2TB HDD 2.5" SATA III 7200rpm for data disk.

Pull the image

The docker image is stored in the Github registry under tioannid/geordfbench/strabonvirtuoso/synthetic. We assume that the current directory is /data/TEST. Then we issue the following commands, which pull the image from the registry, and verify its presence in the docker image list:

tioannid@tioannid-OMEN-by-HP-Laptop-17-an0xx:/data/TEST$ docker pull ghcr.io/tioannid/geordfbench/strabonvirtuoso/synthetic:latest
9b857f539cb1: Already exists 
042803333d0f: Pull complete 
802e38aec4f0: Pull complete 
8f98333ab0b9: Pull complete 
d6b34792240f: Pull complete 
19a6adb15409: Pull complete 
307b7bc41074: Pull complete 
9cc03c9ef44b: Pull complete 
79e05f5e6e0d: Pull complete 
f736660e855f: Pull complete 
6fd4bf1a942e: Pull complete 
Digest: sha256:f6e3c0f411d4bb08691d513880e2a6c87427d18f1cd14e6b02452c81f8138bfc
Status: Downloaded newer image for ghcr.io/tioannid/geordfbench/strabonvirtuoso/synthetic:latest
ghcr.io/tioannid/geordfbench/strabonvirtuoso/synthetic:latest

tioannid@tioannid-OMEN-by-HP-Laptop-17-an0xx:/data/TEST$ docker images
REPOSITORY                                               TAG       IMAGE ID       CREATED          SIZE
ghcr.io/tioannid/geordfbench/strabonvirtuoso/synthetic   latest    caa1c9a83b6e   19 minutes ago   3.56GB
Start a container

We start a container named 2rdfsynth from this image with the following command:

tioannid@tioannid-OMEN-by-HP-Laptop-17-an0xx:/data/TEST$ docker run -e POSTGRES_PASSWORD=postgres -p 5430:5432 --hostname NUC8i7BEH --cpus="4" --memory="24g" \
--memory-swap="24g" --mount "type=bind,src=`pwd`,target=/src" --name 2rdfsynth -d ghcr.io/tioannid/geordfbench/strabonvirtuoso/synthetic
a20ad73da3330813e35644707021e768c5bf567ffa06a39edac80d4c63f9cba2
tioannid@tioannid-OMEN-by-HP-Laptop-17-an0xx:/data/TEST$ docker ps -a
CONTAINER ID   IMAGE                                                    COMMAND               CREATED         STATUS         PORTS                                       NAMES
a20ad73da333   ghcr.io/tioannid/geordfbench/strabonvirtuoso/synthetic   "tail -f /dev/null"   9 seconds ago   Up 8 seconds   0.0.0.0:5430->5432/tcp, :::5430->5432/tcp   2rdfsynth

This command, launches the 2rdfsynth container, while defining:

Inspect the execution specification modifications

In order to better understand this experiment, we need to review the differences between the original Geographica 2 micro execution spec and the modified copy fast micro execution spec. We start by connecting to the 2rdfsynth running container with a terminal and issue the command:

tioannid@tioannid-OMEN-by-HP-Laptop-17-an0xx:/data/TEST$ docker exec -it 2rdfsynth /bin/bash
root@NUC8i7BEH:/data# cd geordfbench/json_defs/executionspecs/
root@NUC8i7BEH:/data/geordfbench/json_defs/executionspecs# diff --color microESoriginal.json microESoriginal_fast.json
4,5c4,5
<     "COLD" : 3,
<     "WARM" : 3
---
>     "COLD" : 1,
>     "WARM" : 1
7,8c7,8
<   "maxDurationSecsPerQueryRep" : 1800,
<   "maxDurationSecs" : 3600,
---
>   "maxDurationSecsPerQueryRep" : 180,
>   "maxDurationSecs" : 360,
12,13c12,13
<   "clearCacheDelaymSecs" : 5000
< }
\ No newline at end of file
---
>   "clearCacheDelaymSecs" : 2000
> }
...

The above coloured diff output shows that we chose to:

Launch the experiments through a terminal

We start the experiments by issuing the command:

root@NUC8i7BEH:/data/geordfbench/json_defs/executionspecs#  cd /data; ./startUpScript.sh
 * Starting PostgreSQL 14 database server                                                                                                                                                                                                                                [ OK ] 
...
CREATE DATABASE
ALTER DATABASE
You are now connected to database "geographica3" as user "postgres".
...
CREATE TABLE
ALTER TABLE
CREATE SEQUENCE
...
GRANT
GRANT
...
[INFO] Installing /data/util_misc/virt_rdf4j.jar to /root/.m2/repository/com/virtuoso/openlink/virt_rdf4j/3.7.6/virt_rdf4j-3.7.6.jar
[INFO] Installing /tmp/mvninstall17143710146034283251.pom to /root/.m2/repository/com/virtuoso/openlink/virt_rdf4j/3.7.6/virt_rdf4j-3.7.6.pom
[INFO] ------------------------------------------------------------------------
[INFO] BUILD SUCCESS
[INFO] ------------------------------------------------------------------------
[INFO] Total time:  6.487 s
[INFO] Finished at: 2024-08-12T09:16:11Z
[INFO] ------------------------------------------------------------------------
[INFO] Scanning for projects...
[INFO] 
[INFO] ------------------< org.apache.maven:standalone-pom >-------------------
[INFO] Building Maven Stub Project (No POM) 1
[INFO] --------------------------------[ pom ]---------------------------------
[INFO] 
[INFO] --- maven-install-plugin:2.4:install-file (default-cli) @ standalone-pom ---
[INFO] Installing /data/util_misc/virtjdbc4_2.jar to /root/.m2/repository/com/virtuoso/openlink/virtjdbc4_2/4.2/virtjdbc4_2-4.2.jar
[INFO] Installing /tmp/mvninstall12645222801424534056.pom to /root/.m2/repository/com/virtuoso/openlink/virtjdbc4_2/4.2/virtjdbc4_2-4.2.pom
[INFO] ------------------------------------------------------------------------
[INFO] BUILD SUCCESS
[INFO] ------------------------------------------------------------------------
[INFO] Total time:  0.292 s
[INFO] Finished at: 2024-08-12T09:16:12Z
[INFO] ------------------------------------------------------------------------
...

The default terminal will act as a log window and after some time each one of the 2 experiments will conclude with the statistics report and export. As shown below, in red color, Virtuoso timedout during scanning while executing Query 24, but in the 180 sec time window managed to retrieve 3800 out of the 459523 results. Strabon on the other hand managed this spatial join query well within the 180 sec time window specified.

...
261856 [main] INFO  GenericExprerimentResultsCollector  - Export statistics in "/data/Results_Store/VirtuosoSUT/2024-08-12_VirtuosoSUT_Run_Synth/SyntheticWorkload/VirtuosoSUT-Experiment"
261857 [main] INFO  GenericExprerimentResultsCollector  - Created non existing directory
261859 [main] INFO  GenericExprerimentResultsCollector  - Statistiscs printed: /data/Results_Store/VirtuosoSUT/2024-08-12_VirtuosoSUT_Run_Synth/SyntheticWorkload/VirtuosoSUT-Experiment/00-Synthetic_Selection_Intersects_1_1.0-cold
261859 [main] INFO  GenericExprerimentResultsCollector  - Statistiscs printed: /data/Results_Store/VirtuosoSUT/2024-08-12_VirtuosoSUT_Run_Synth/SyntheticWorkload/VirtuosoSUT-Experiment/00-Synthetic_Selection_Intersects_1_1.0-cold-long
261860 [main] INFO  GenericExprerimentResultsCollector  - Statistiscs printed: /data/Results_Store/VirtuosoSUT/2024-08-12_VirtuosoSUT_Run_Synth/SyntheticWorkload/VirtuosoSUT-Experiment/24-Synthetic_Join_Intersects_1_1-cold
261860 [main] INFO  GenericExprerimentResultsCollector  - Statistiscs printed: /data/Results_Store/VirtuosoSUT/2024-08-12_VirtuosoSUT_Run_Synth/SyntheticWorkload/VirtuosoSUT-Experiment/24-Synthetic_Join_Intersects_1_1-cold-long
261860 [main] INFO  GenericExprerimentResultsCollector  - Statistiscs printed: /data/Results_Store/VirtuosoSUT/2024-08-12_VirtuosoSUT_Run_Synth/SyntheticWorkload/VirtuosoSUT-Experiment/00-Synthetic_Selection_Intersects_1_1.0-warm
261860 [main] INFO  GenericExprerimentResultsCollector  - Statistiscs printed: /data/Results_Store/VirtuosoSUT/2024-08-12_VirtuosoSUT_Run_Synth/SyntheticWorkload/VirtuosoSUT-Experiment/00-Synthetic_Selection_Intersects_1_1.0-warm-long
261860 [main] INFO  GenericExprerimentResultsCollector  - Statistiscs printed: /data/Results_Store/VirtuosoSUT/2024-08-12_VirtuosoSUT_Run_Synth/SyntheticWorkload/VirtuosoSUT-Experiment/24-Synthetic_Join_Intersects_1_1-warm
261860 [main] INFO  GenericExprerimentResultsCollector  - Statistiscs printed: /data/Results_Store/VirtuosoSUT/2024-08-12_VirtuosoSUT_Run_Synth/SyntheticWorkload/VirtuosoSUT-Experiment/24-Synthetic_Join_Intersects_1_1-warm-long
261860 [main] INFO  GenericExprerimentResultsCollector  - Cache COLD
261860 [main] INFO  GenericExprerimentResultsCollector  - 	Query 0
261861 [main] INFO  GenericExprerimentResultsCollector  - 		Rep 0	<COMPLETED-NONE> 288806638 + 2202823963 = 2491630601 nsecs, 262144 results, 0 scan errors
261861 [main] INFO  GenericExprerimentResultsCollector  - 	Query 24
261861 [main] INFO  GenericExprerimentResultsCollector  - 		Rep 0	<SCANNING-TIMEDOUT> 500270486 + 181495929084 = 181996199570 nsecs, 3800 results, 0 scan errors
261861 [main] INFO  GenericExprerimentResultsCollector  - Cache WARM
261861 [main] INFO  GenericExprerimentResultsCollector  - 	Query 0
261861 [main] INFO  GenericExprerimentResultsCollector  - 		Rep 0	<COMPLETED-NONE> 9995971 + 1941576588 = 1951572559 nsecs, 262144 results, 0 scan errors
261861 [main] INFO  GenericExprerimentResultsCollector  - 	Query 24
261861 [main] INFO  GenericExprerimentResultsCollector  - 		Rep 0	<SCANNING-TIMEDOUT> 500270486 + 181495929084 = 181996199570 nsecs, 3800 results, 0 scan errors
261861 [main] INFO  RunVirtuosoExperiment  - End synthetic-synthetic
Start time = Mon Aug 12 09:16:56 UTC 2024
End time = Mon Aug 12 09:21:19 UTC 2024
...
103619 [main] INFO  GenericExprerimentResultsCollector  - Export statistics in "/data/Results_Store/StrabonSUT/2024-08-12_StrabonSUT_Run_Synth/SyntheticWorkload/StrabonSUT-Experiment"
103619 [main] INFO  GenericExprerimentResultsCollector  - Created non existing directory
103621 [main] INFO  GenericExprerimentResultsCollector  - Statistiscs printed: /data/Results_Store/StrabonSUT/2024-08-12_StrabonSUT_Run_Synth/SyntheticWorkload/StrabonSUT-Experiment/00-Synthetic_Selection_Intersects_1_1.0-cold
103621 [main] INFO  GenericExprerimentResultsCollector  - Statistiscs printed: /data/Results_Store/StrabonSUT/2024-08-12_StrabonSUT_Run_Synth/SyntheticWorkload/StrabonSUT-Experiment/00-Synthetic_Selection_Intersects_1_1.0-cold-long
103621 [main] INFO  GenericExprerimentResultsCollector  - Statistiscs printed: /data/Results_Store/StrabonSUT/2024-08-12_StrabonSUT_Run_Synth/SyntheticWorkload/StrabonSUT-Experiment/24-Synthetic_Join_Intersects_1_1-cold
103621 [main] INFO  GenericExprerimentResultsCollector  - Statistiscs printed: /data/Results_Store/StrabonSUT/2024-08-12_StrabonSUT_Run_Synth/SyntheticWorkload/StrabonSUT-Experiment/24-Synthetic_Join_Intersects_1_1-cold-long
103621 [main] INFO  GenericExprerimentResultsCollector  - Statistiscs printed: /data/Results_Store/StrabonSUT/2024-08-12_StrabonSUT_Run_Synth/SyntheticWorkload/StrabonSUT-Experiment/00-Synthetic_Selection_Intersects_1_1.0-warm
103622 [main] INFO  GenericExprerimentResultsCollector  - Statistiscs printed: /data/Results_Store/StrabonSUT/2024-08-12_StrabonSUT_Run_Synth/SyntheticWorkload/StrabonSUT-Experiment/00-Synthetic_Selection_Intersects_1_1.0-warm-long
103622 [main] INFO  GenericExprerimentResultsCollector  - Statistiscs printed: /data/Results_Store/StrabonSUT/2024-08-12_StrabonSUT_Run_Synth/SyntheticWorkload/StrabonSUT-Experiment/24-Synthetic_Join_Intersects_1_1-warm
103622 [main] INFO  GenericExprerimentResultsCollector  - Statistiscs printed: /data/Results_Store/StrabonSUT/2024-08-12_StrabonSUT_Run_Synth/SyntheticWorkload/StrabonSUT-Experiment/24-Synthetic_Join_Intersects_1_1-warm-long
103622 [main] INFO  GenericExprerimentResultsCollector  - Cache COLD
103622 [main] INFO  GenericExprerimentResultsCollector  - 	Query 0
103622 [main] INFO  GenericExprerimentResultsCollector  - 		Rep 0	<COMPLETED-NONE> 1197621911 + 212018215 = 1409640126 nsecs, 262144 results, 0 scan errors
103622 [main] INFO  GenericExprerimentResultsCollector  - 	Query 24
103622 [main] INFO  GenericExprerimentResultsCollector  - 		Rep 0	<COMPLETED-NONE> 8132088691 + 310050926 = 8442139617 nsecs, 459523 results, 0 scan errors
103622 [main] INFO  GenericExprerimentResultsCollector  - Cache WARM
103622 [main] INFO  GenericExprerimentResultsCollector  - 	Query 0
103622 [main] INFO  GenericExprerimentResultsCollector  - 		Rep 0	<COMPLETED-NONE> 925583295 + 53618794 = 979202089 nsecs, 262144 results, 0 scan errors
103622 [main] INFO  GenericExprerimentResultsCollector  - 	Query 24
103622 [main] INFO  GenericExprerimentResultsCollector  - 		Rep 0	<COMPLETED-NONE> 8547460400 + 213653135 = 8761113535 nsecs, 459523 results, 0 scan errors
103622 [main] INFO  RunStrabonExperiment  - End synthetic-synthetic
Start time = Mon Aug 12 09:48:28 UTC 2024
End time = Mon Aug 12 09:50:12 UTC 2024
Verify that the repositories have been created
root@NUC8i7BEH:/data# tree -L 1 virtuoso-opensource/repos
virtuoso-opensource/repos
`-- synthetic

root@NUC8i7BEH:/data# su postgres
postgres@NUC8i7BEH:/data$ psql --list
                                       List of databases
       Name       |    Owner     | Encoding |   Collate   |    Ctype    |   Access privileges   
------------------+--------------+----------+-------------+-------------+-----------------------
 geographica3     | geographica3 | UTF8     | en_US.UTF-8 | en_US.UTF-8 | 
 postgres         | postgres     | UTF8     | C.UTF-8     | C.UTF-8     | 
 synthetic        | postgres     | UTF8     | C.UTF-8     | C.UTF-8     | 
 template0        | postgres     | UTF8     | C.UTF-8     | C.UTF-8     | =c/postgres          +
                  |              |          |             |             | postgres=CTc/postgres
 template1        | postgres     | UTF8     | C.UTF-8     | C.UTF-8     | =c/postgres          +
                  |              |          |             |             | postgres=CTc/postgres
 template_postgis | postgres     | UTF8     | C.UTF-8     | C.UTF-8     | 

postgres@NUC8i7BEH:/data$ exit
Verify that the repository creation logs have been generated
root@NUC8i7BEH:/data# ls -lsa geordfbench/VirtuosoSUT/scripts/CreateRepos/*.log
4 -rw-r--r-- 1 root root 3833 Aug 12 09:16 geordfbench/VirtuosoSUT/scripts/CreateRepos/logCreateRepos_Synthetic_Virtuoso.log
root@NUC8i7BEH:/data# ls -lsa geordfbench/StrabonSUT/scripts/PostgresUtils/CreateDatasetDBs/*.log
16 -rw-r--r-- 1 root root 15763 Aug 12 09:48 geordfbench/StrabonSUT/scripts/PostgresUtils/CreateDatasetDBs/logCreateRepo_Synth_Strabon.log
Verify that the experiment logs have been generated

Experiment run logs may be quite long, therefore the user can click the links below to view the details of the execution.

root@NUC8i7BEH:/data# ls -lsa geordfbench/VirtuosoSUT/scripts/RunTests3/*.log
24 -rw-r--r-- 1 root root 22727 Aug 12 09:21 geordfbench/VirtuosoSUT/scripts/RunTests3/RunVirtuosoExp_Synth.log
root@NUC8i7BEH:/data# ls -lsa geordfbench/StrabonSUT/scripts/RunTests3/*.log
36 -rw-r--r-- 1 root root 28675 Aug 12 09:50 geordfbench/StrabonSUT/scripts/RunTests3/RunStrabonExp_Synth.log
Verify that the experiment results have been generated in the Default Location

Experiment results are stored by default in the file system. For this demonstration the base location for all results was /data/Results_Store. The output of the following command has been modified to fully expand the last entry only, with the result of tree -L 4 Results_Store/VirtuosoSUT/ :

root@NUC8i7BEH:/data# tree -L 2 Results_Store/
Results_Store/
|-- StrabonSUT
|   `-- 2024-08-12_StrabonSUT_Run_Synth
`-- VirtuosoSUT
    `-- 2024-08-12_VirtuosoSUT_Run_Synth
        `-- SyntheticWorkload
            `-- VirtuosoSUT-Experiment
                |-- 00-Synthetic_Selection_Intersects_1_1.0-cold
                |-- 00-Synthetic_Selection_Intersects_1_1.0-cold-long
                |-- 00-Synthetic_Selection_Intersects_1_1.0-warm
                |-- 00-Synthetic_Selection_Intersects_1_1.0-warm-long
                |-- 24-Synthetic_Join_Intersects_1_1-cold
                |-- 24-Synthetic_Join_Intersects_1_1-cold-long
                |-- 24-Synthetic_Join_Intersects_1_1-warm
                `-- 24-Synthetic_Join_Intersects_1_1-warm-long

root@NUC8i7BEH:/data# more Results_Store/VirtuosoSUT/2024-08-12_VirtuosoSUT_Run_Synth/SyntheticWorkload/VirtuosoSUT-Experiment/00-Synthetic_Selection_Intersects_1_1.0-cold
262144 2491630601
root@NUC8i7BEH:/data# more Results_Store/VirtuosoSUT/2024-08-12_VirtuosoSUT_Run_Synth/SyntheticWorkload/VirtuosoSUT-Experiment/00-Synthetic_Selection_Intersects_1_1.0-cold-long
262144 288806638 2202823963 2491630601
root@NUC8i7BEH:/data# more Results_Store/VirtuosoSUT/2024-08-12_VirtuosoSUT_Run_Synth/SyntheticWorkload/VirtuosoSUT-Experiment/24-Synthetic_Join_Intersects_1_1-cold
3800 181996199570
root@NUC8i7BEH:/data# more Results_Store/VirtuosoSUT/2024-08-12_VirtuosoSUT_Run_Synth/SyntheticWorkload/VirtuosoSUT-Experiment/24-Synthetic_Join_Intersects_1_1-cold-long
3800 500270486 181495929084 181996199570

For each query and execution type (warm, cold) there are two files, a short and a long version. The long version has 4 columns (noOfResults, evaluationTime, scanTime, totalTime) and one row for each execution iteration performed. The short version has 2 columns (noOfResults, totalTime) and only one row which represents the average or median totalTime of the execution iterations from the long version. All times are in nano seconds. Please notice, that both experiments used the customized execution specification fast micro execution spec which dictates 1 repetition for COLD and 1 repetition for WARN caches.

Verify that the experiment results have been generated in the PostgreSQL database

Experiment results are also stored in a custom location, a PostgreSQL database. Each experiment details are recorded, with a unique ID, in a row of the EXPERIMENTS table. Each query execution iteration details are in a similar manner recorded in the QUERYEXECUTIONS table. A set of views can provide aggregation for the totalTime and calculation of the Average and Median value of totalTime for each query and execution type (warm, cold). All times are in milli seconds. In the figures below we can see the actual snapshots from the PgAdmin v4 interface with the experiment details on the left and the report results on the right side.

Experiment Entries
Fig.1 - Experiment entries
Experiment report results
Fig.2 - Experiment report results
Charting the report results

Below we present how we can transport the report data from Figure 2, to a LibreOffice Calc worksheet and create the corresponding charts. For simplicity purposes we will include the Virtuoso Failed executions which, depending on the benchmark researcher's point of view, can be excluded or included in the results discussion.

Synthetic workload charts from exported data
Fig.3 - Synthetic workload - COLD and WARM caches charts from report data

The above chart shows clearly that for the Synthetic workload, Strabon performed better than Virtuoso. In this chart we can also see, that for the non timed out queries the WARM cache times are lower than the COLD cache ones. This occurs even though it is known that clearing caches fail inside the container. However, both systems feature some kind of server component, Strabon features a PostgreSQL database server and Virtuoso an application server. Restarting the server components in such "server-based" RDF stores is part of the clear cache action employed before measuring a COLD run. Therefore in this situation we have a partial clear cache which explains the COLD to WARM cache execution time differences.

Handling query execution time outs

The modified fast micro execution spec, was designed with the intension to cause Virtuoso to timeout while executing the spatial join query and thus provide us the opportunity to exhibit and study how GeoRDFBench Framework manages this situation. The following is an annonated excerpt of the /data/geordfbench/VirtuosoSUT/scripts/RunTests3/RunVirtuosoExp_Synth.log log file:

...
45200 [main] INFO  VirtuosoSUT  - Starting Virtuoso server...
57206 [main] INFO  VirtuosoSystem  - Uninitialized VirtuosoRepository created with query timeout = 0
57206 [main] INFO  VirtuosoSystem  - Initialized VirtuosoRepository has query timeout = 180
57213 [main] INFO  VirtuosoSUT  - Starting QueryExecutor thread
57213 [main] INFO  VirtuosoSUT  - Waiting for QueryExecutor thread to finish
57213 [main] INFO  VirtuosoSUT  - Timeout progress step is 45000 msecs
57214 [Thread-2] INFO  QueryRepResult  - Transitioning (NOTSTARTED => STARTED)
57215 [Thread-2] INFO  QueryRepResult  - Transitioning (STARTED => PREPARING)
57215 [Thread-2] INFO  QueryRepResult  - Transitioning (PREPARING => EVALUATING)
57715 [Thread-2] INFO  QueryRepResult  - Transitioning (EVALUATING => EVALUATED)
57715 [Thread-2] INFO  RDF4JbasedExecutor  - 	s1		s2		
57715 [Thread-2] INFO  RDF4JbasedExecutor  - ------------------------------------>
57716 [Thread-2] INFO  QueryRepResult  - Transitioning (EVALUATED => SCANNING)
57716 [Thread-2] INFO  RDF4JbasedExecutor  - http://geographica.di.uoa.gr/generator/landOwnership/255721/	http://geographica.di.uoa.gr/generator/state/28298/	
63337 [Thread-2] INFO  RDF4JbasedExecutor  - http://geographica.di.uoa.gr/generator/landOwnership/255722/	http://geographica.di.uoa.gr/generator/state/28298/	
63337 [Thread-2] INFO  RDF4JbasedExecutor  - http://geographica.di.uoa.gr/generator/landOwnership/255722/	http://geographica.di.uoa.gr/generator/state/28299/ 
102214 [main] INFO  VirtuosoSUT  - Percentage of expired timeout is 25.0 %
147214 [main] INFO  VirtuosoSUT  - Percentage of expired timeout is 50.0 %
192214 [main] INFO  VirtuosoSUT  - Percentage of expired timeout is 75.0 %
237214 [main] INFO  VirtuosoSUT  - Timeout expired! Sent interrupt to worker thread and waiting for it to join.
239212 [Thread-2] ERROR RDF4JbasedExecutor  - RuntimeException - I wasn't done! Query prepared and evaluated. Scanning in progress ...3800 results, so far. Not big enough patience window defined... :(
239220 [main] INFO  Experiment  - |<== Executed query [24, Synthetic_Join_Intersects_1_1] (COLD, 0): <SCANNING-TIMEDOUT> 500270486 + 181495929084 = 181996199570 nsecs, 3800 results, 0 scan errors - ACCURACY NOT DETERMINED
239220 [main] INFO  VirtuosoSUT  - Closing..
239220 [main] INFO  VirtuosoSystem  - Closing connection...
239220 [main] INFO  VirtuosoSystem  - Repository closed.
241229 [main] INFO  VirtuosoSUT  - Closed (caches not cleared)
241229 [main] INFO  VirtuosoSUT  - Stopping Virtuoso server...
...

The above log excerpt, focuses on the COLD execution of Query 24 Synthetic_Join_Intersects_1_1 by Virtuoso. Under GeoRDFBench a query is run as described below:

Explanation of what happened?

The more interested user, can look at the simple Bash script, /data/startUpScript.sh, which launched the experiments. The actions taken by this script are: