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

[René-Luc Dhont]

Thanks Nyall,

I have tested Hotspot and the result is interesting :
* 48.7% of the time is due to QgsRasterProjector::block that provide 
projected raster block
* 26.6% of the time is due to ProjectorData::srcRowCol that identify the 
source row col corresponding to the destination row col

Is some enhancement could e done here ?

Regards,
René-Luc

Le 05/10/2020 à 05:31, Nyall Dawson a écrit :
> 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