[QGIS-Developer] The virtual QgsRasterInterface block method is too slow

[Nyall Dawson]

On Fri, 2 Oct 2020 at 00:53, René-Luc Dhont <rldhont at gmail.com> wrote:
>
> Hi devs,
>
> A customer found that reading a lightweight GeoTIFF takes 1 second in
> QGIS Server needs less than 200 milliseconds.
>
> With timer I found somethings strange around the virtual
> QgsRasterInterface block method and it's reimplation in QgsGdalProvider.
> Here is part of my logs:
>
> ../src/core/raster/qgsrasteriterator.cpp:87 :
> (readNextRasterPartInternal) [2ms] Entered
> ../src/core/providers/gdal/qgsgdalprovider.cpp:2641 : (initIfNeeded)
> [1ms] GdalDataset opened
> ../src/core/providers/gdal/qgsgdalprovider.cpp:317 : (crsFromWkt) [0ms]
> +proj=aea +lat_1=43 +lat_2=62 +lat_0=30 +lon_0=-30 +x_0=0 +y_0=0
> +datum=WGS84 +units=m +no_defs
> ../src/core/providers/gdal/qgsgdalprovider.cpp:2836 : (initBaseDataset)
> [0ms] GDALGetRasterNoDataValue = -3.4e+38
> ../src/core/providers/gdal/qgsgdalprovider.cpp:647 : (block) [10ms]
> QgsGdalProvider::block
> ../src/core/providers/gdal/qgsgdalprovider.cpp:718 : (readBlock) [0ms]
> QgsGdalProvider::readBlock
> ../src/core/providers/gdal/qgsgdalprovider.cpp:965 : (readBlock) [2ms]
> QgsGdalProvider::readBlock completed in (seconds): 0.002
> ../src/core/providers/gdal/qgsgdalprovider.cpp:684 : (block) [0ms]
> QgsGdalProvider::block completed in (seconds): 0.002
> ../src/core/raster/qgsrasteriterator.cpp:137 :
> (readNextRasterPartInternal) [643ms] Raster iterator read next block
> completed in (seconds): 0.656
> ../src/core/raster/qgsrasteriterator.cpp:87 :
> (readNextRasterPartInternal) [3ms] Entered
> ../src/core/providers/gdal/qgsgdalprovider.cpp:647 : (block) [6ms]
> QgsGdalProvider::block
> ../src/core/providers/gdal/qgsgdalprovider.cpp:718 : (readBlock) [0ms]
> QgsGdalProvider::readBlock
> ../src/core/providers/gdal/qgsgdalprovider.cpp:965 : (readBlock) [0ms]
> QgsGdalProvider::readBlock completed in (seconds): 0
> ../src/core/providers/gdal/qgsgdalprovider.cpp:684 : (block) [0ms]
> QgsGdalProvider::block completed in (seconds): 0
> ../src/core/raster/qgsrasteriterator.cpp:137 :
> (readNextRasterPartInternal) [283ms] Raster iterator read next block
> completed in (seconds): 0.289
> ../src/core/raster/qgsrasteriterator.cpp:87 :
> (readNextRasterPartInternal) [0ms] Entered
>
>
> The qgsrasterinterator.cpp ligne 130 [1] tooks almost 300 times longer
> than it's reimplementation.
>
> Do you know a way to enhance this ?

I'd caution against reading too much into the debug output timings. My
suggestion is to re-run the tests using hotspot
(https://github.com/KDAB/hotspot) as this will give much more useful
information about the bottlenecks.

Nyall