MapCache Performance Analysis A Case Study

Story and design

A satellite imagery provider wants a browser to display its product catalog. Each product is an image of a small area on Earth (about 100km wide) and there are hundreds of products. Of course the browser should be as fast as possible.

The solution is built around MapCache serving selected products through its WMS/WMTS map services. Products are preprocessed to take the form of SQLite caches or Geopackages directly accessible by MapCache. Product selection takes place using dimension feature of those services. This is implemented with second level dimensions in MapCache, so that new products can be added without interrupting MapCache service.

Mockup

In order to compare various implementation choices with respect to MapCache performance, a mockup is created inside a Docker container or a Vagrant//VirtualBox virtual machine. Actual implementation is made available in jbo-ads/mapcache-mockup GitHub repository.

Download

$ git clone https://github/jbo-ads/mapcache-mockup.git
$ cd mapcache-mockup

Installation and startup

Docker

$ sudo docker build --tag mapcache .
$ sudo docker run

$ sudo docker run -dit -p 8888:80 -v $(pwd):/share --name mapcache mapcache
$ sudo docker exec -it mapcache /share/bin/setup.sh

Vagrant

$ vagrant up

Run

Open link at http://localhost:8888/ol/ when using Docker or http://localhost:8080/ol/ when using Vagrant.

How to observe MapCache operation

Client-side

Client-side observations include all possible delays from local system load to network speed and actual Apache/MapCache execution. This gives information on actual user feeling about MapCache performance.

On client-side, one can measure how long a tile or a map is served. This feature is provided by "Developer" menu on common graphic web browsers. This is also possible on a Linux command line interface with a combination of time and curl commands, e.g.:

$ time curl -s "http://localhost:8888/world/wmts?SERVICE=WMTS&REQUEST=GetTile&LAYER=world&TILEMATRIXSET=GoogleMapsCompatible&TILEMATRIX=0&TILEROW=0&TILECOL=0 > tile

real    0m0.078s
user    0m0.035s
sys     0m0.013s

Server-side

Server-side observations focus on actual MapCache performance and allows for identifying possible bottlenecks.

On server-side, the main observation point is the Apache error log, which is time-tagged to the microsecond. The log level is configured in Apache configuration file with the LogLevel keyword, e.g.:

LogLevel warn mapcache:debug

Apache error log can be retrieved with following commands, depending on the used container.

Docker

$ sudo docker exec -it mapcache cp /var/log/apache2/error.log /share

Vagrant

$ vagrant ssh -c "sudo cp /var/log/apache2/error.log /share"

Here is an example of a log entry in Apache error log:

[Mon Jan 06 13:44:11.716120 2020] [mapcache:debug] [pid 46:tid 140338173826816] mod_mapcache.c(448): [client 172.17.0.1:51862] mapcache quick handler hook on uri /world, referer: http://localhost:8888/ol/

In order to observe detailed behaviour of MapCache, one needs to insert debug traces in MapCache code put at places of interest, in particular at function beginning and end. This first example shows how to measure the overall time needed by MapCache to serve a request.

    $ git diff -U1 apache/mod_mapcache.c
    diff --git a/apache/mod_mapcache.c b/apache/mod_mapcache.c
    index 5e5c437..b081d70 100644
    --- a/apache/mod_mapcache.c
    +++ b/apache/mod_mapcache.c
    @@ -345,2 +345,3 @@ static int mapcache_handler(request_rec *r, mapcache_alias_entry *alias_entry) {
 
    +  ap_log_rerror(APLOG_MARK, APLOG_DEBUG, 0, r, "MOCKUP BEGIN mapcache_handler");
       //ap_log_rerror(APLOG_MARK, APLOG_DEBUG, 0, r, "mapcache dispatch %s",r->path_info);
    @@ -349,2 +350,3 @@ static int mapcache_handler(request_rec *r, mapcache_alias_entry *alias_entry) {
       if(GC_HAS_ERROR(ctx) || !request) {
    +    ap_log_rerror(APLOG_MARK, APLOG_DEBUG, 0, r, "MOCKUP END mapcache_handler ERROR");
         return write_http_response(apache_ctx,
    @@ -390,2 +392,3 @@ static int mapcache_handler(request_rec *r, mapcache_alias_entry *alias_entry) {
           if(GC_HAS_ERROR(ctx)) {
    +        ap_log_rerror(APLOG_MARK, APLOG_DEBUG, 0, r, "MOCKUP END mapcache_handler ERROR");
             return write_http_response(apache_ctx, mapcache_core_respond_to_error(ctx));
    @@ -436,2 +439,3 @@ static int mapcache_handler(request_rec *r, mapcache_alias_entry *alias_entry) {
       if(GC_HAS_ERROR(ctx)) {
    +    ap_log_rerror(APLOG_MARK, APLOG_DEBUG, 0, r, "MOCKUP END mapcache_handler ERROR");
         return write_http_response(apache_ctx,
    @@ -439,2 +443,3 @@ static int mapcache_handler(request_rec *r, mapcache_alias_entry *alias_entry) {
       }
    +  ap_log_rerror(APLOG_MARK, APLOG_DEBUG, 0, r, "MOCKUP END mapcache_handler");
       return write_http_response(apache_)ctx,http_response);

With that instrumentation, a WMS request on the World at zoom level 2 gives the following (abridged) traces:

[Mon Jan 06 15:09:24.192378 2020] [...] MOCKUP BEGIN mapcache_handler
[Mon Jan 06 15:09:24.249737 2020] [...] MOCKUP END mapcache_handler

The map has been served in 57539 µs.

Simulating a satellite image catalog

For this performance analysis, a satellite image catalog is simulated by creating pseudo-imagery from existing tiled data sources, e.g.:

OSM Tiles (Map data © by OpenStreetMap contributors, available under ODbL)
OSM WMS (Map data © by OpenStreetMap contributors, available under ODbL)

A simulated product is generated by following these two steps:

Create a detailed GeoTiff image from the source. It covers a square area of 10x10 tiles at zoom level 12, i.e. about 100km x 100km (with EPSG:3857 projection). This simulates a preprocessed picture taken from a satellite.
Build a tile pyramid from that image, stored in a SQLite file that can be used as a MapCache cache.

The catalog itself is implemented using a SQLite database. All product names and bounding boxes are stored in a table. This SQLite database is used as second dimension backend by MapCache.

Tools to generate simulated products

The mockup integrates two tools in /share/bin folder of Docker container or Vagrant virtual machine:

genprod.sh generates a single simulated product based on the image center coordinates and its orientation: horizontal, vertical or square. It is also able to generate multiple random products inside a given bounding box.
build-catalog.sh generates all products of the catalog used in this analysis.

Catalog used in the analysis

The catalog of simulated products is composed of several product groups:

UN cities: This group is composed of images representing cities where United Nations agencies are located, i.e., Bern, Geneva, London, Madrid, Montreal, Nairobi, New York, Paris, The Hague, Rome, Vienna and Washington DC. This group is used to show how MapCache operates to serve a map, specifically with second level dimensions.

Observations

Getting a single tile from a disk cache

To illustrate how MapCache operates, let's request a single tile at level 0 on the "Low resolution World" layer, which is also the catalog basemap. From command line on host with mockup running in Docker container, the instruction is:

$ curl -s "http://localhost:8888/catalog/wmts/1.0.0/base/default/GoogleMapsCompatible/0/0/0" > base-0-0-0.jpg

With appropriate instrumentation in MapCache code, resulting Apache log shows the execution path from initial request to tile retrieval. It also gives various times along that execution path with a total duration of 157 µs for mapcache_handler() execution:

    [... 16:47:37.032595 ... pid 21682:tid 140040353081088 ...] mapcache quick handler hook on uri /catalog/wmts
    [... 16:47:37.032824 ... pid 21682:tid 140040353081088 ...] MOCKUP BEGIN mapcache_handler
    [... 16:47:37.032854 ... pid 21682:tid 140040353081088 ...] MOCKUP BEGIN mapcache_core_get_tile
    [... 16:47:37.032861 ... pid 21682:tid 140040353081088 ...] MOCKUP BEGIN mapcache_prefetch_tiles
    [... 16:47:37.032870 ... pid 21682:tid 140040353081088 ...] MOCKUP BEGIN mapcache_tileset_tile_get
    [... 16:47:37.032876 ... pid 21682:tid 140040353081088 ...] MOCKUP BEGIN mapcache_tileset_tile_get_without_subdimensions
    [... 16:47:37.032886 ... pid 21682:tid 140040353081088 ...] MOCKUP BEGIN mapcache_cache_tile_get
    [... 16:47:37.032896 ... pid 21682:tid 140040353081088 ...] MOCKUP BEGIN _mapcache_cache_disk_get
    [... 16:47:37.032908 ... pid 21682:tid 140040353081088 ...] checking for tile /share/caches/world/0/0/0.jpg
    [... 16:47:37.032936 ... pid 21682:tid 140040353081088 ...] MOCKUP END _mapcache_cache_disk_get
    [... 16:47:37.032941 ... pid 21682:tid 140040353081088 ...] MOCKUP END mapcache_cache_tile_get
    [... 16:47:37.032947 ... pid 21682:tid 140040353081088 ...] MOCKUP END mapcache_tileset_tile_get_without_subdimensions
    [... 16:47:37.032952 ... pid 21682:tid 140040353081088 ...] MOCKUP END mapcache_tileset_tile_get
    [... 16:47:37.032958 ... pid 21682:tid 140040353081088 ...] MOCKUP END mapcache_prefetch_tiles
    [... 16:47:37.032976 ... pid 21682:tid 140040353081088 ...] MOCKUP END mapcache_core_get_tile
    [... 16:47:37.032981 ... pid 21682:tid 140040353081088 ...] MOCKUP END mapcache_handler

Getting a single tile from a SQLite cache

A similar request is performed on a SQLite cache:

$ curl -s "http://localhost:8888/osm/wmts/1.0.0/wikimedia/default/GoogleMapsCompatible/0/0/0" > wikimedia-0-0-0.jpg

This gives the following log (total duration: 1.19 ms, with 850 µs in _mapcache_cache_sqlite_get() alone):

    [... 10:06:15.149617 ... pid 476:tid 139635938281216 ...] mapcache quick handler hook on uri /osm/wmts
    [... 10:06:15.149828 ... pid 476:tid 139635938281216 ...] MOCKUP BEGIN mapcache_handler
    [... 10:06:15.149860 ... pid 476:tid 139635938281216 ...] MOCKUP BEGIN mapcache_core_get_tile
    [... 10:06:15.149866 ... pid 476:tid 139635938281216 ...] MOCKUP BEGIN mapcache_prefetch_tiles
    [... 10:06:15.149880 ... pid 476:tid 139635938281216 ...] MOCKUP BEGIN mapcache_tileset_tile_get
    [... 10:06:15.149887 ... pid 476:tid 139635938281216 ...] MOCKUP BEGIN mapcache_tileset_tile_get_without_subdimensions
    [... 10:06:15.149896 ... pid 476:tid 139635938281216 ...] MOCKUP BEGIN mapcache_cache_tile_get
    [... 10:06:15.149907 ... pid 476:tid 139635938281216 ...] MOCKUP BEGIN _mapcache_cache_sqlite_get
    [... 10:06:15.150757 ... pid 476:tid 139635938281216 ...] MOCKUP END _mapcache_cache_sqlite_get
    [... 10:06:15.150771 ... pid 476:tid 139635938281216 ...] MOCKUP END mapcache_cache_tile_get
    [... 10:06:15.150776 ... pid 476:tid 139635938281216 ...] MOCKUP END mapcache_tileset_tile_get_without_subdimensions
    [... 10:06:15.150781 ... pid 476:tid 139635938281216 ...] MOCKUP END mapcache_tileset_tile_get
    [... 10:06:15.150786 ... pid 476:tid 139635938281216 ...] MOCKUP END mapcache_prefetch_tiles
    [... 10:06:15.150802 ... pid 476:tid 139635938281216 ...] MOCKUP END mapcache_core_get_tile
    [... 10:06:15.150807 ... pid 476:tid 139635938281216 ...] MOCKUP END mapcache_handler

Getting a 4-tiles map from a SQLite cache

Here, the WMS protocol is used to get a worldwide map at zoom level 1.

$ curl -s "http://localhost:8888/osm?SERVICE=WMS&REQUEST=GetMap&BBOX=-20037508.342789,-20037508.342789,20037508.342789,20037508.342789&WIDTH=512&HEIGHT=512&SRS=EPSG:3857&LAYERS=wikimedia" > wikimedia-1.jpg

    [... 13:29:36.199004 ... pid 475:tid 139636500330240 ...] mapcache quick handler hook on uri /osm
    [... 13:29:36.199088 ... pid 475:tid 139636500330240 ...] MOCKUP BEGIN mapcache_handler
    [... 13:29:36.199112 ... pid 475:tid 139636500330240 ...] MOCKUP BEGIN mapcache_prefetch_tiles
    [... 13:29:36.199119 ... pid 475:tid 139636500330240 ...] MOCKUP BEGIN mapcache_tileset_tile_get
    [... 13:29:36.199126 ... pid 475:tid 139636500330240 ...] MOCKUP BEGIN mapcache_tileset_tile_get_without_subdimensions
    [... 13:29:36.199133 ... pid 475:tid 139636500330240 ...] MOCKUP BEGIN mapcache_cache_tile_get
    [... 13:29:36.199147 ... pid 475:tid 139636500330240 ...] MOCKUP BEGIN _mapcache_cache_sqlite_get
    [... 13:29:36.199227 ... pid 475:tid 139636500330240 ...] MOCKUP END _mapcache_cache_sqlite_get
    [... 13:29:36.199235 ... pid 475:tid 139636500330240 ...] MOCKUP END mapcache_cache_tile_get
    [... 13:29:36.199242 ... pid 475:tid 139636500330240 ...] MOCKUP END mapcache_tileset_tile_get_without_subdimensions
    [... 13:29:36.199256 ... pid 475:tid 139636500330240 ...] MOCKUP END mapcache_tileset_tile_get
    [... 13:29:36.199267 ... pid 475:tid 139636500330240 ...] MOCKUP BEGIN mapcache_tileset_tile_get
    [... 13:29:36.199297 ... pid 475:tid 139636500330240 ...] MOCKUP BEGIN mapcache_tileset_tile_get_without_subdimensions
    [... 13:29:36.199305 ... pid 475:tid 139636500330240 ...] MOCKUP BEGIN mapcache_cache_tile_get
    [... 13:29:36.199315 ... pid 475:tid 139636500330240 ...] MOCKUP BEGIN _mapcache_cache_sqlite_get
    [... 13:29:36.199401 ... pid 475:tid 139636500330240 ...] MOCKUP END _mapcache_cache_sqlite_get
    [... 13:29:36.199410 ... pid 475:tid 139636500330240 ...] MOCKUP END mapcache_cache_tile_get
    [... 13:29:36.199417 ... pid 475:tid 139636500330240 ...] MOCKUP END mapcache_tileset_tile_get_without_subdimensions
    [... 13:29:36.199428 ... pid 475:tid 139636500330240 ...] MOCKUP END mapcache_tileset_tile_get
    [... 13:29:36.199440 ... pid 475:tid 139636500330240 ...] MOCKUP BEGIN mapcache_tileset_tile_get
    [... 13:29:36.199448 ... pid 475:tid 139636500330240 ...] MOCKUP BEGIN mapcache_tileset_tile_get_without_subdimensions
    [... 13:29:36.199458 ... pid 475:tid 139636500330240 ...] MOCKUP BEGIN mapcache_cache_tile_get
    [... 13:29:36.199467 ... pid 475:tid 139636500330240 ...] MOCKUP BEGIN _mapcache_cache_sqlite_get
    [... 13:29:36.199523 ... pid 475:tid 139636500330240 ...] MOCKUP END _mapcache_cache_sqlite_get
    [... 13:29:36.199532 ... pid 475:tid 139636500330240 ...] MOCKUP END mapcache_cache_tile_get
    [... 13:29:36.199544 ... pid 475:tid 139636500330240 ...] MOCKUP END mapcache_tileset_tile_get_without_subdimensions
    [... 13:29:36.199557 ... pid 475:tid 139636500330240 ...] MOCKUP END mapcache_tileset_tile_get
    [... 13:29:36.199566 ... pid 475:tid 139636500330240 ...] MOCKUP BEGIN mapcache_tileset_tile_get
    [... 13:29:36.199574 ... pid 475:tid 139636500330240 ...] MOCKUP BEGIN mapcache_tileset_tile_get_without_subdimensions
    [... 13:29:36.199582 ... pid 475:tid 139636500330240 ...] MOCKUP BEGIN mapcache_cache_tile_get
    [... 13:29:36.199595 ... pid 475:tid 139636500330240 ...] MOCKUP BEGIN _mapcache_cache_sqlite_get
    [... 13:29:36.199661 ... pid 475:tid 139636500330240 ...] MOCKUP END _mapcache_cache_sqlite_get
    [... 13:29:36.199670 ... pid 475:tid 139636500330240 ...] MOCKUP END mapcache_cache_tile_get
    [... 13:29:36.199684 ... pid 475:tid 139636500330240 ...] MOCKUP END mapcache_tileset_tile_get_without_subdimensions
    [... 13:29:36.199695 ... pid 475:tid 139636500330240 ...] MOCKUP END mapcache_tileset_tile_get
    [... 13:29:36.199710 ... pid 475:tid 139636500330240 ...] MOCKUP END mapcache_prefetch_tiles
    [... 13:29:36.212821 ... pid 475:tid 139636500330240 ...] MOCKUP END mapcache_handler

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

Uh oh!

MapCache Performance Analysis A Case Study

Story and design

Mockup

Download

Installation and startup

Docker

Vagrant

Run

How to observe MapCache operation

Client-side

Server-side

Docker

Vagrant

Simulating a satellite image catalog

Tools to generate simulated products

Catalog used in the analysis

Observations

Getting a single tile from a disk cache

Getting a single tile from a SQLite cache

Getting a 4-tiles map from a SQLite cache

Uh oh!

Uh oh!

Clone this wiki locally