[QGIS-Developer] Qgis server: terrible performance with Qgis 3.26
David Marteau
dmarteau at 3liz.com
Tue Jun 21 05:45:58 PDT 2022
Hi,
Here is a first analysis using QgsRuntimeProfiler outputs
The project is the same in all tests and has been saved with Qgis 3.26.
This is a first load in each case just after qgis init, so there should
be no caching involved.
Output has been filtered to `projectload` profiler group and rows with
elapsed time > 0
All builds are official builds and installed from qgis.org packages.
Tests are run in Docker container with ubuntu 21.04
Total time show a variance of +/- 25% on multiple runs.
## Qgis 3.26
### Flags
* Qgis.ProjectReadFlag.TrustLayerMetadata
* Qgis.ProjectReadFlag.DontLoad3DViews
* Qgis.ProjectReadFlag.DontLoadProjectStyles
projectload, Reading project file: 21.0 ms
projectload, Creating auxiliary storage: 65.0 ms
projectload, Reading properties: 19.0 ms
projectload, Reading map layers: 14.0 ms
-projectload, france_parts: 6.0 ms
--projectload, Load layer source: 5.0 ms
---projectload, Create ogr provider: 3.0 ms
-projectload, france_parts bordure: 4.0 ms
--projectload, Load layer source: 4.0 ms
---projectload, Create ogr provider: 2.0 ms
-projectload, france_parts tuilé en cache: 3.0 ms
--projectload, Load layer source: 3.0 ms
---projectload, Create ogr provider: 1.0 ms
projectload, Storing original layer properties: 2.0 ms
Total time: 152.0 ms
## Qgis 3.24
### Flags
* QgsProject.FlagTrustLayerMetadata
projectload, Reading project file: 5.0 ms
projectload, Reading properties: 4.0 ms
projectload, Reading map layers: 4.0 ms
-projectload, france_parts: 1.0 ms
--projectload, Load layer source: 1.0 ms
-projectload, france_parts bordure: 1.0 ms
--projectload, Load layer source: 1.0 ms
-projectload, france_parts tuilé en cache: 1.0 ms
--projectload, Load layer source: 1.0 ms
projectload, Storing original layer properties: 1.0 ms
projectload, Updating interface: 1.0 ms
Total time: 21.0 ms
Some remarks:
I Wonder why we have `Creating auxiliary storage` that takes 65.0 ms in
Qgis 3.26 and it does not appears in Qgis 3.24:
I need to figure how auxiliary layers are loaded in Qgis 3.24 (are they
loaded lazily ?).
The `Reading project file`, `Reading properties` and `Reading map
layers` sections are almost 3 to 4 times slower in Qgis 3.26.
The loading of layers ares also slower in Qgis 3.26 compared to Qgis 3.24.
Le 21/06/2022 à 12:27, David Marteau a écrit :
>
>
> May be I could use QgsRuntimeProfiler output in first place ?
>
> Le 20/06/2022 à 18:55, Even Rouault a écrit :
>>
>> Use sysprof or just run under a debugger and interrupt regularly
>> should help you spot in which method(s) most time is spent
>>
>> Le 20/06/2022 à 18:48, David Marteau via QGIS-Developer a écrit :
>>>
>>> I used the following test:
>>>
>>> readflags = Qgis.ProjectReadFlags() readflags |=
>>> Qgis.ProjectReadFlag.TrustLayerMetadata|Qgis.ProjectReadFlag.DontLoad3DViews|Qgis.ProjectReadFlag.DontLoadProjectStyles
>>> prj = QgsProject()%timeit -n 1
>>> prj.read(f"{datapath}/france_parts3_26.qgs",readflags)
>>>
>>> 105 ms ± 18.5 ms per loop (mean ± std. dev. of 7 runs, 1 loop each)
>>>
>>> This improve the result but we are still much higher that the
>>> loading time of 3.24: 15ms compared to 105ms
>>>
>>>
>>> Le 20/06/2022 à 18:38, Nyall Dawson a écrit :
>>>>
>>>>
>>>> On Mon, 20 June 2022, 11:42 pm David Marteau, <dmarteau at 3liz.com>
>>>> wrote:
>>>>
>>>> Hi,
>>>>
>>>> > You should set the other new read optimisation flags here --
>>>> see
>>>> https://github.com/qgis/QGIS/blob/88ebb3f2f513dbce5a775f50e51ea0117f859c65/src/core/qgis.h#L1962
>>>>
>>>> These are already available also in 3.24 and we use the
>>>> `TrustLayerMetadata` in the above test. For server, the other
>>>> flags are not applicable (Getprint requests need print layouts ).
>>>>
>>>> So that mean we are comparing 3.24 to 3.26 with same level of
>>>> read optimisation and that does not change the fact that, for
>>>> that very same level of read optimisation, project's loading is
>>>> incredibly slower in 3.26.
>>>>
>>>>
>>>> You'll need to set the new flags relating to skipping the 3d views
>>>> and project style loading in order to compare properly. Neither of
>>>> those things were occurring in 3.24, and both have an associated
>>>> cost. And neither are relevant for server.
>>>>
>>>> Nyall
>>>>
>>>>
>>>>
>>>> Le 20/06/2022 à 15:10, Nyall Dawson a écrit :
>>>>>
>>>>>
>>>>> On Mon, 20 June 2022, 9:37 pm David Marteau via
>>>>> QGIS-Developer, <qgis-developer at lists.osgeo.org> wrote:
>>>>>
>>>>> Hi,
>>>>>
>>>>> I have noticed a huge drop of performance while testing
>>>>> Qgis server with Qgis 3.26, from 10x to 30x slower as usual.
>>>>>
>>>>> Trying to reduce the problem I have found a huge increase
>>>>> of time spend reading the project in 3.26 compared to 3.24.
>>>>>
>>>>> Here some benchmark with very simple project from the test
>>>>> data set. Note: the project has been updated with qgis 3.26:
>>>>>
>>>>> Qgis 3.24:
>>>>> ======
>>>>>
>>>>> readflags = QgsProject.ReadFlags()readflags |=
>>>>> QgsProject.FlagTrustLayerMetadata
>>>>>
>>>>> prj = QgsProject()
>>>>>
>>>>> %timeit -n 1
>>>>> prj.read(f"{datapath}/france_parts.qgs",readflags)
>>>>>
>>>>> > 15.7 ms ± 205 µs per loop (mean ± std. dev. of 7 runs, 1 loop each)
>>>>>
>>>>> Qgis 3.26:
>>>>> ======
>>>>>
>>>>> readflags = QgsProject.ReadFlags() readflags |=
>>>>> QgsProject.FlagTrustLayerMetadata
>>>>>
>>>>>
>>>>> You should set the other new read optimisation flags here --
>>>>> see
>>>>> https://github.com/qgis/QGIS/blob/88ebb3f2f513dbce5a775f50e51ea0117f859c65/src/core/qgis.h#L1962
>>>>>
>>>>> Nyall
>>>>>
>>>>> prj = QgsProject()
>>>>>
>>>>> %timeit -n 1
>>>>> prj.read(f"{datapath}/france_parts.qgs",readflags)
>>>>>
>>>>> 195 ms ± 44 ms per loop (mean ± std. dev. of 7 runs, 1 loop each)
>>>>>
>>>>> There is a factor x10 between Qgis 3.24 et Qgis 3.26 for
>>>>> the exact same project.
>>>>> This has serious impact on requests: landing page catalog
>>>>> request time increased from approximatevely 110ms to more
>>>>> than 3.0s with our test data set.
>>>>>
>>>>>
>>>>> David Marteau
>>>>> www.3liz.com <http://www.3liz.com>
>>>>>
>>>>> _______________________________________________
>>>>> QGIS-Developer mailing list
>>>>> QGIS-Developer at lists.osgeo.org
>>>>> List info:
>>>>> https://lists.osgeo.org/mailman/listinfo/qgis-developer
>>>>> Unsubscribe:
>>>>> https://lists.osgeo.org/mailman/listinfo/qgis-developer
>>>>>
>>>
>>> _______________________________________________
>>> QGIS-Developer mailing list
>>> QGIS-Developer at lists.osgeo.org
>>> List info:https://lists.osgeo.org/mailman/listinfo/qgis-developer
>>> Unsubscribe:https://lists.osgeo.org/mailman/listinfo/qgis-developer
>> --
>> http://www.spatialys.com
>> My software is free, but my time generally not.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.osgeo.org/pipermail/qgis-developer/attachments/20220621/f1b9f3fe/attachment.htm>
More information about the QGIS-Developer
mailing list