[gdal-dev] WMTS huge difference in performance - cache issue

Fri Jun 28 05:59:47 PDT 2024

Hi,
I have two sample WMTS servers.
The first is a Polish geoportal:
https://mapy.geoportal.gov.pl/wss/service/WMTS/guest/wmts/G2_MOBILE_500
and the second is German:
https://basemap.de/dienste/wmts_capabilities_web_raster.xml
Both work well in QGIS.
I use C API for creating bitmaps in my area of interest.
I use GDALDatasetRasterIO function directly with WMTS dataset and
appropriate arguments.
The first Polish server works smoothly for different extents, different
widths and heights of my output image. Unfortunately, the second one
(German) lasts forever.
During debugging I concluded the thesis that every GDALDatasetRasterIO in
my loop over raster lines, GDAL do not use cache but redownload the same
tiles.

Below is a fragment from GDAL log for well-working Polish server:

*[Fri Jun 28 13:06:16 2024].5430, 66.7590: HTTP: Requesting [1/3]
http://mapy.geoportal.gov.pl/wss/service/WMTS/guest/wmts/G2_MOBILE_500?service=WMTS&request=GetTile&version=1.0.0&layer=G2_MOBILE_500&style=default&format=image/png&TileMatrixSet=EPSG:2180&TileMatrix=EPSG:2180:4&TileRow=2&TileCol=0
<http://mapy.geoportal.gov.pl/wss/service/WMTS/guest/wmts/G2_MOBILE_500?service=WMTS&request=GetTile&version=1.0.0&layer=G2_MOBILE_500&style=default&format=image/png&TileMatrixSet=EPSG:2180&TileMatrix=EPSG:2180:4&TileRow=2&TileCol=0>[Fri
Jun 28 13:06:16 2024].5430, 66.7590: HTTP: Requesting [2/3]
http://mapy.geoportal.gov.pl/wss/service/WMTS/guest/wmts/G2_MOBILE_500?service=WMTS&request=GetTile&version=1.0.0&layer=G2_MOBILE_500&style=default&format=image/png&TileMatrixSet=EPSG:2180&TileMatrix=EPSG:2180:4&TileRow=2&TileCol=1
<http://mapy.geoportal.gov.pl/wss/service/WMTS/guest/wmts/G2_MOBILE_500?service=WMTS&request=GetTile&version=1.0.0&layer=G2_MOBILE_500&style=default&format=image/png&TileMatrixSet=EPSG:2180&TileMatrix=EPSG:2180:4&TileRow=2&TileCol=1>[Fri
Jun 28 13:06:16 2024].6670, 66.8830: HTTP: Requesting [3/3]
http://mapy.geoportal.gov.pl/wss/service/WMTS/guest/wmts/G2_MOBILE_500?service=WMTS&request=GetTile&version=1.0.0&layer=G2_MOBILE_500&style=default&format=image/png&TileMatrixSet=EPSG:2180&TileMatrix=EPSG:2180:4&TileRow=2&TileCol=2
<http://mapy.geoportal.gov.pl/wss/service/WMTS/guest/wmts/G2_MOBILE_500?service=WMTS&request=GetTile&version=1.0.0&layer=G2_MOBILE_500&style=default&format=image/png&TileMatrixSet=EPSG:2180&TileMatrix=EPSG:2180:4&TileRow=2&TileCol=2>[Fri
Jun 28 13:06:16 2024].8230, 67.0390: HTTP: Request [0]
http://mapy.geoportal.gov.pl/wss/service/WMTS/guest/wmts/G2_MOBILE_500?service=WMTS&request=GetTile&version=1.0.0&layer=G2_MOBILE_500&style=default&format=image/png&TileMatrixSet=EPSG:2180&TileMatrix=EPSG:2180:4&TileRow=2&TileCol=0
<http://mapy.geoportal.gov.pl/wss/service/WMTS/guest/wmts/G2_MOBILE_500?service=WMTS&request=GetTile&version=1.0.0&layer=G2_MOBILE_500&style=default&format=image/png&TileMatrixSet=EPSG:2180&TileMatrix=EPSG:2180:4&TileRow=2&TileCol=0>
: status = 200, type = image/png, error = (null)[Fri Jun 28 13:06:16
2024].8230, 67.0390: HTTP: Request [1]
http://mapy.geoportal.gov.pl/wss/service/WMTS/guest/wmts/G2_MOBILE_500?service=WMTS&request=GetTile&version=1.0.0&layer=G2_MOBILE_500&style=default&format=image/png&TileMatrixSet=EPSG:2180&TileMatrix=EPSG:2180:4&TileRow=2&TileCol=1
<http://mapy.geoportal.gov.pl/wss/service/WMTS/guest/wmts/G2_MOBILE_500?service=WMTS&request=GetTile&version=1.0.0&layer=G2_MOBILE_500&style=default&format=image/png&TileMatrixSet=EPSG:2180&TileMatrix=EPSG:2180:4&TileRow=2&TileCol=1>
: status = 200, type = image/png, error = (null)[Fri Jun 28 13:06:16
2024].8230, 67.0390: HTTP: Request [2]
http://mapy.geoportal.gov.pl/wss/service/WMTS/guest/wmts/G2_MOBILE_500?service=WMTS&request=GetTile&version=1.0.0&layer=G2_MOBILE_500&style=default&format=image/png&TileMatrixSet=EPSG:2180&TileMatrix=EPSG:2180:4&TileRow=2&TileCol=2
<http://mapy.geoportal.gov.pl/wss/service/WMTS/guest/wmts/G2_MOBILE_500?service=WMTS&request=GetTile&version=1.0.0&layer=G2_MOBILE_500&style=default&format=image/png&TileMatrixSet=EPSG:2180&TileMatrix=EPSG:2180:4&TileRow=2&TileCol=2>
: status = 200, type = image/png, error = (null)[Fri Jun 28 13:06:16
2024].8240, 67.0400: GDAL:
GDALOpen(/vsimem/wms/0000022663367550/wmsresult.dat, this=000002266059B0E0)
succeeds as PNG.[Fri Jun 28 13:06:16 2024].8260, 67.0420: GDAL:
GDALClose(/vsimem/wms/0000022663367550/wmsresult.dat,
this=000002266059B0E0)[Fri Jun 28 13:06:16 2024].8270, 67.0430: GDAL:
GDALOpen(/vsimem/wms/00000226632272D0/wmsresult.dat, this=000002266059B0E0)
succeeds as PNG.[Fri Jun 28 13:06:16 2024].8300, 67.0460: GDAL:
GDALClose(/vsimem/wms/00000226632272D0/wmsresult.dat,
this=000002266059B0E0)[Fri Jun 28 13:06:16 2024].8300, 67.0460: GDAL:
GDALOpen(/vsimem/wms/0000022661BEC8D0/wmsresult.dat, this=000002266059B0E0)
succeeds as PNG.[Fri Jun 28 13:06:16 2024].8330, 67.0490: GDAL:
GDALClose(/vsimem/wms/0000022661BEC8D0/wmsresult.dat,
this=000002266059B0E0) *
And here is log snippet for German server:

*[Fri Jun 28 13:16:02 2024].0840, 652.3000: HTTP: Requesting [1/5]
https://sgx.geodatenzentrum.de/wmts_basemapde/tile/1.0.0/de_basemapde_web_raster_farbe/default/DE_EPSG_25832_ADV/02/0/0.png
<https://sgx.geodatenzentrum.de/wmts_basemapde/tile/1.0.0/de_basemapde_web_raster_farbe/default/DE_EPSG_25832_ADV/02/0/0.png>[Fri
Jun 28 13:16:02 2024].0840, 652.3000: HTTP: Requesting [2/5]
https://sgx.geodatenzentrum.de/wmts_basemapde/tile/1.0.0/de_basemapde_web_raster_farbe/default/DE_EPSG_25832_ADV/02/0/1.png
<https://sgx.geodatenzentrum.de/wmts_basemapde/tile/1.0.0/de_basemapde_web_raster_farbe/default/DE_EPSG_25832_ADV/02/0/1.png>[Fri
Jun 28 13:16:02 2024].2690, 652.4850: HTTP: Requesting [3/5]
https://sgx.geodatenzentrum.de/wmts_basemapde/tile/1.0.0/de_basemapde_web_raster_farbe/default/DE_EPSG_25832_ADV/02/0/2.png
<https://sgx.geodatenzentrum.de/wmts_basemapde/tile/1.0.0/de_basemapde_web_raster_farbe/default/DE_EPSG_25832_ADV/02/0/2.png>[Fri
Jun 28 13:16:02 2024].2870, 652.5030: HTTP: Requesting [4/5]
https://sgx.geodatenzentrum.de/wmts_basemapde/tile/1.0.0/de_basemapde_web_raster_farbe/default/DE_EPSG_25832_ADV/02/0/3.png
<https://sgx.geodatenzentrum.de/wmts_basemapde/tile/1.0.0/de_basemapde_web_raster_farbe/default/DE_EPSG_25832_ADV/02/0/3.png>[Fri
Jun 28 13:16:02 2024].3140, 652.5300: HTTP: Requesting [5/5]
https://sgx.geodatenzentrum.de/wmts_basemapde/tile/1.0.0/de_basemapde_web_raster_farbe/default/DE_EPSG_25832_ADV/02/0/4.png
<https://sgx.geodatenzentrum.de/wmts_basemapde/tile/1.0.0/de_basemapde_web_raster_farbe/default/DE_EPSG_25832_ADV/02/0/4.png>[Fri
Jun 28 13:16:02 2024].5970, 652.8130: HTTP: Request [0]
https://sgx.geodatenzentrum.de/wmts_basemapde/tile/1.0.0/de_basemapde_web_raster_farbe/default/DE_EPSG_25832_ADV/02/0/0.png
<https://sgx.geodatenzentrum.de/wmts_basemapde/tile/1.0.0/de_basemapde_web_raster_farbe/default/DE_EPSG_25832_ADV/02/0/0.png>
: status = 200, type = image/png, error = (null)[Fri Jun 28 13:16:02
2024].5970, 652.8130: HTTP: Request [1]
https://sgx.geodatenzentrum.de/wmts_basemapde/tile/1.0.0/de_basemapde_web_raster_farbe/default/DE_EPSG_25832_ADV/02/0/1.png
<https://sgx.geodatenzentrum.de/wmts_basemapde/tile/1.0.0/de_basemapde_web_raster_farbe/default/DE_EPSG_25832_ADV/02/0/1.png>
: status = 200, type = image/png, error = (null)[Fri Jun 28 13:16:02
2024].5970, 652.8130: HTTP: Request [2]
https://sgx.geodatenzentrum.de/wmts_basemapde/tile/1.0.0/de_basemapde_web_raster_farbe/default/DE_EPSG_25832_ADV/02/0/2.png
<https://sgx.geodatenzentrum.de/wmts_basemapde/tile/1.0.0/de_basemapde_web_raster_farbe/default/DE_EPSG_25832_ADV/02/0/2.png>
: status = 200, type = image/png, error = (null)[Fri Jun 28 13:16:02
2024].5970, 652.8130: HTTP: Request [3]
https://sgx.geodatenzentrum.de/wmts_basemapde/tile/1.0.0/de_basemapde_web_raster_farbe/default/DE_EPSG_25832_ADV/02/0/3.png
<https://sgx.geodatenzentrum.de/wmts_basemapde/tile/1.0.0/de_basemapde_web_raster_farbe/default/DE_EPSG_25832_ADV/02/0/3.png>
: status = 200, type = image/png, error = (null)[Fri Jun 28 13:16:02
2024].5970, 652.8130: HTTP: Request [4]
https://sgx.geodatenzentrum.de/wmts_basemapde/tile/1.0.0/de_basemapde_web_raster_farbe/default/DE_EPSG_25832_ADV/02/0/4.png
<https://sgx.geodatenzentrum.de/wmts_basemapde/tile/1.0.0/de_basemapde_web_raster_farbe/default/DE_EPSG_25832_ADV/02/0/4.png>
: status = 0, type = (null), error = (null)[Fri Jun 28 13:16:02 2024].5970,
652.8130: GDAL: GDALOpen(/vsimem/wms/0000022661D59690/wmsresult.dat,
this=000002266059B0E0) succeeds as PNG.[Fri Jun 28 13:16:02 2024].5990,
652.8150: GDAL: GDALClose(/vsimem/wms/0000022661D59690/wmsresult.dat,
this=000002266059B0E0)[Fri Jun 28 13:16:02 2024].6190, 652.8350: WMS: Clean
cache[Fri Jun 28 13:16:02 2024].6190, 652.8350: GDAL:
GDALOpen(/vsimem/wms/000002266237A190/wmsresult.dat, this=000002266059B0E0)
succeeds as PNG.[Fri Jun 28 13:16:02 2024].6200, 652.8360: GDAL:
GDALClose(/vsimem/wms/000002266237A190/wmsresult.dat,
this=000002266059B0E0)[Fri Jun 28 13:16:02 2024].6340, 652.8500: GDAL:
GDALOpen(/vsimem/wms/0000022662340E00/wmsresult.dat, this=000002266059B0E0)
succeeds as PNG.[Fri Jun 28 13:16:02 2024].6340, 652.8500: GDAL:
GDALClose(/vsimem/wms/0000022662340E00/wmsresult.dat,
this=000002266059B0E0)[Fri Jun 28 13:16:02 2024].6350, 652.8510: GDAL:
GDALOpen(/vsimem/wms/00000226605A35B0/wmsresult.dat, this=000002266059B0E0)
succeeds as PNG.[Fri Jun 28 13:16:02 2024].6360, 652.8520: GDAL:
GDALClose(/vsimem/wms/00000226605A35B0/wmsresult.dat,
this=000002266059B0E0)[Fri Jun 28 13:16:02 2024].6360, 652.8520: WMS:
ReadBlockFromCache[Fri Jun 28 13:16:02 2024].6370, 652.8530: CPLError:
./gdalwmscache\76ac5c8f3010af4e1a17a26a53e6ac32/0/b/0bab9c0d45a96010ec0092c98e78a52d:
No such file or directoryERROR 4:
./gdalwmscache\76ac5c8f3010af4e1a17a26a53e6ac32/0/b/0bab9c0d45a96010ec0092c98e78a52d:
No such file or directory[Fri Jun 28 13:16:02 2024].6370, 652.8530:
CPLError: GDALWMS: Unable to open downloaded block.ERROR 1: GDALWMS: Unable
to open downloaded block.[Fri Jun 28 13:16:02 2024].6370, 652.8530: WMS:
After ReadBlockFromCache[Fri Jun 28 13:16:02 2024].6370, 652.8530:
CPLError: GDALWMS: Unable to download block 4, 0.URL:   HTTP status code:
0, error: (null).Add the HTTP status code to <ZeroBlockHttpCodes> to ignore
this error (see http://www.gdal.org/frmt_wms.html
<http://www.gdal.org/frmt_wms.html>).ERROR 1: GDALWMS: Unable to download
block 4, 0.URL:   HTTP status code: 0, error: (null).Add the HTTP status
code to <ZeroBlockHttpCodes> to ignore this error (see
http://www.gdal.org/frmt_wms.html <http://www.gdal.org/frmt_wms.html>).[Fri
Jun 28 13:16:02 2024].6370, 652.8530: CPLError: GDAL_WMS>, band 3:
IReadBlock failed at X offset 0, Y offset 0: GDALWMS: Unable to download
block 4, 0.URL:   HTTP status code: 0, error: (null).Add the HTTP status
code to <ZeroBlockHttpCodes> to ignore this error (see
http://www.gdal.org/frmt_wms.html
<http://www.gdal.org/frmt_wms.html>).ERROR 1: GDAL_WMS>, band 3: IReadBlock
failed at X offset 0, Y offset 0: GDALWMS: Unable to download block 4,
0.URL:   HTTP status code: 0, error: (null).Add the HTTP status code to
<ZeroBlockHttpCodes> to ignore this error (see
http://www.gdal.org/frmt_wms.html <http://www.gdal.org/frmt_wms.html>).[Fri
Jun 28 13:16:02 2024].6380, 652.8540: GDAL:
GDALOpen(./gdalwmscache\76ac5c8f3010af4e1a17a26a53e6ac32/1/5/15b3159bb18ea6f97264bd4d0bac680e,
this=000002266059B0E0) succeeds as PNG.[Fri Jun 28 13:16:02 2024].6380,
652.8540: GDAL:
GDALClose(./gdalwmscache\76ac5c8f3010af4e1a17a26a53e6ac32/1/5/15b3159bb18ea6f97264bd4d0bac680e,
this=000002266059B0E0)[Fri Jun 28 13:16:02 2024].6390, 652.8550: HTTP:
Requesting [1/1]
https://sgx.geodatenzentrum.de/wmts_basemapde/tile/1.0.0/de_basemapde_web_raster_farbe/default/DE_EPSG_25832_ADV/02/0/4.png
<https://sgx.geodatenzentrum.de/wmts_basemapde/tile/1.0.0/de_basemapde_web_raster_farbe/default/DE_EPSG_25832_ADV/02/0/4.png>[Fri
Jun 28 13:16:02 2024].8540, 653.0700: HTTP: Request [0]
https://sgx.geodatenzentrum.de/wmts_basemapde/tile/1.0.0/de_basemapde_web_raster_farbe/default/DE_EPSG_25832_ADV/02/0/4.png
<https://sgx.geodatenzentrum.de/wmts_basemapde/tile/1.0.0/de_basemapde_web_raster_farbe/default/DE_EPSG_25832_ADV/02/0/4.png>
: status = 0, type = (null), error = (null)[Fri Jun 28 13:16:02 2024].8540,
653.0700: WMS: ReadBlockFromCache[Fri Jun 28 13:16:02 2024].8550, 653.0710:
CPLError:
./gdalwmscache\76ac5c8f3010af4e1a17a26a53e6ac32/0/b/0bab9c0d45a96010ec0092c98e78a52d:
No such file or directoryERROR 4:
./gdalwmscache\76ac5c8f3010af4e1a17a26a53e6ac32/0/b/0bab9c0d45a96010ec0092c98e78a52d:
No such file or directory[Fri Jun 28 13:16:02 2024].8550, 653.0710:
CPLError: GDALWMS: Unable to open downloaded block.ERROR 1: GDALWMS: Unable
to open downloaded block.[Fri Jun 28 13:16:02 2024].8550, 653.0710: WMS:
After ReadBlockFromCache[Fri Jun 28 13:16:02 2024].8550, 653.0710:
CPLError: GDALWMS: Unable to download block 4, 0.URL:   HTTP status code:
0, error: (null).Add the HTTP status code to <ZeroBlockHttpCodes> to ignore
this error (see http://www.gdal.org/frmt_wms.html
<http://www.gdal.org/frmt_wms.html>).ERROR 1: GDALWMS: Unable to download
block 4, 0.URL:   HTTP status code: 0, error: (null).Add the HTTP status
code to <ZeroBlockHttpCodes> to ignore this error (see
http://www.gdal.org/frmt_wms.html <http://www.gdal.org/frmt_wms.html>).[Fri
Jun 28 13:16:02 2024].8550, 653.0710: CPLError: GDAL_WMS>, band 3:
IReadBlock failed at X offset 0, Y offset 0: GDALWMS: Unable to download
block 4, 0.URL:   HTTP status code: 0, error: (null).Add the HTTP status
code to <ZeroBlockHttpCodes> to ignore this error (see
http://www.gdal.org/frmt_wms.html
<http://www.gdal.org/frmt_wms.html>).ERROR 1: GDAL_WMS>, band 3: IReadBlock
failed at X offset 0, Y offset 0: GDALWMS: Unable to download block 4,
0.URL:   HTTP status code: 0, error: (null).Add the HTTP status code to
<ZeroBlockHttpCodes> to ignore this error (see
http://www.gdal.org/frmt_wms.html <http://www.gdal.org/frmt_wms.html>).[Fri
Jun 28 13:16:02 2024].8560, 653.0720: GDAL:
GDALOpen(./gdalwmscache\76ac5c8f3010af4e1a17a26a53e6ac32/1/5/15b3159bb18ea6f97264bd4d0bac680e,
this=000002266059B0E0) succeeds as PNG.[Fri Jun 28 13:16:02 2024].8560,
653.0720: GDAL:
GDALClose(./gdalwmscache\76ac5c8f3010af4e1a17a26a53e6ac32/1/5/15b3159bb18ea6f97264bd4d0bac680e,
this=000002266059B0E0)[Fri Jun 28 13:16:02 2024].8570, 653.0730: HTTP:
Requesting [1/1]
https://sgx.geodatenzentrum.de/wmts_basemapde/tile/1.0.0/de_basemapde_web_raster_farbe/default/DE_EPSG_25832_ADV/02/0/4.png
<https://sgx.geodatenzentrum.de/wmts_basemapde/tile/1.0.0/de_basemapde_web_raster_farbe/default/DE_EPSG_25832_ADV/02/0/4.png>[Fri
Jun 28 13:16:03 2024].0760, 653.2920: HTTP: Request [0]
https://sgx.geodatenzentrum.de/wmts_basemapde/tile/1.0.0/de_basemapde_web_raster_farbe/default/DE_EPSG_25832_ADV/02/0/4.png
<https://sgx.geodatenzentrum.de/wmts_basemapde/tile/1.0.0/de_basemapde_web_raster_farbe/default/DE_EPSG_25832_ADV/02/0/4.png>
: status = 0, type = (null), error = (null)[Fri Jun 28 13:16:03 2024].0760,
653.2920: WMS: ReadBlockFromCache[Fri Jun 28 13:16:03 2024].0760, 653.2920:
CPLError:
./gdalwmscache\76ac5c8f3010af4e1a17a26a53e6ac32/0/b/0bab9c0d45a96010ec0092c98e78a52d:
No such file or directoryERROR 4:
./gdalwmscache\76ac5c8f3010af4e1a17a26a53e6ac32/0/b/0bab9c0d45a96010ec0092c98e78a52d:
No such file or directory[Fri Jun 28 13:16:03 2024].0760, 653.2920:
CPLError: GDALWMS: Unable to open downloaded block.ERROR 1: GDALWMS: Unable
to open downloaded block.[Fri Jun 28 13:16:03 2024].0760, 653.2920: WMS:
After ReadBlockFromCache[Fri Jun 28 13:16:03 2024].0760, 653.2920:
CPLError: GDALWMS: Unable to download block 4, 0.URL:   HTTP status code:
0, error: (null).Add the HTTP status code to <ZeroBlockHttpCodes> to ignore
this error (see http://www.gdal.org/frmt_wms.html
<http://www.gdal.org/frmt_wms.html>).ERROR 1: GDALWMS: Unable to download
block 4, 0.URL:   HTTP status code: 0, error: (null).Add the HTTP status
code to <ZeroBlockHttpCodes> to ignore this error (see
http://www.gdal.org/frmt_wms.html <http://www.gdal.org/frmt_wms.html>).[Fri
Jun 28 13:16:03 2024].0760, 653.2920: CPLError: GDAL_WMS>, band 3:
IReadBlock failed at X offset 0, Y offset 0: GDALWMS: Unable to download
block 4, 0.URL:   HTTP status code: 0, error: (null).Add the HTTP status
code to <ZeroBlockHttpCodes> to ignore this error (see
http://www.gdal.org/frmt_wms.html
<http://www.gdal.org/frmt_wms.html>).ERROR 1: GDAL_WMS>, band 3: IReadBlock
failed at X offset 0, Y offset 0: GDALWMS: Unable to download block 4,
0.URL:   HTTP status code: 0, error: (null).Add the HTTP status code to
<ZeroBlockHttpCodes> to ignore this error (see
http://www.gdal.org/frmt_wms.html <http://www.gdal.org/frmt_wms.html>).*

How you see, GDAL tries to open cache that does not exist.
But in fact, it exist. I found all necessary tile for full extent map
request in gdalwmscache folder.
I can not send it in this email because of message size limits.

Regards,
Michał
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.osgeo.org/pipermail/gdal-dev/attachments/20240628/f65beabd/attachment-0001.htm>