Re: [QGIS-Developer] Qgis server: terrible performance with Qgis 3.26

2022-07-07 Thread Nyall Dawson via QGIS-Developer 
On Tue, 28 Jun 2022 at 23:30, David Marteau via QGIS-Developer
 wrote:
>
> Hi,
>
> From bisect-like analysis, I have found the commit that introduces the loss 
> of loading performance:
>
> https://github.com/qgis/QGIS/commit/c6beb62216fcfbfe3ca64283c09117da53800a98
>
> We need more investigation to understand exactly what is causing that 
> regression.

I've proposed a fix at https://github.com/qgis/QGIS/pull/49266, but it
requires testing on server and confirmation that it addresses the
regression.

Thanks!
Nyall



>
> David Marteau
> www.3liz.com
>
> Le 21/06/2022 à 14:45, David Marteau via QGIS-Developer a écrit :
>
> 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,  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 Martea

Re: [QGIS-Developer] Qgis server: terrible performance with Qgis 3.26

2022-06-28 Thread David Marteau via QGIS-Developer 

Hi,

From bisect-like analysis, I have found the commit that introduces the 
loss of loading performance:


https://github.com/qgis/QGIS/commit/c6beb62216fcfbfe3ca64283c09117da53800a98

We need more investigation to understand exactly what is causing that 
regression.


David Marteau
www.3liz.com 

Le 21/06/2022 à 14:45, David Marteau via QGIS-Developer a écrit :


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,  
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,  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

Re: [QGIS-Developer] Qgis server: terrible performance with Qgis 3.26

2022-06-21 Thread David Marteau via QGIS-Developer 
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 ?).


I happends that loading auxiliary layer is negligible in 3.24 :

>> projectload, Creating auxiliary storage: 0.0 ms

I do not understand the difference because it appears that it looks like 
the same code in 3.24 and 3.26.


Does compile/optimize options could have changed between release 3.24 
and 3.26 ?



Le 21/06/2022 à 14:45, David Marteau a écrit :


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,  
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,  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 in

Re: [QGIS-Developer] Qgis server: terrible performance with Qgis 3.26

2022-06-21 Thread David Marteau via QGIS-Developer 

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,  
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,  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:
==

Re: [QGIS-Developer] Qgis server: terrible performance with Qgis 3.26

2022-06-21 Thread David Marteau via QGIS-Developer 


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,  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,
 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 

___
QGIS-Developer mailing list
QGIS-Developer@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@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.___
QGIS-Developer mailing list
QGIS-Developer@lists.osgeo.org
List info: https://lists.osgeo.org/mailman/listinfo/qgis-developer
Unsubscribe: https://lists.osgeo.org/mailman/listinfo/qgis-developer

Re: [QGIS-Developer] Qgis server: terrible performance with Qgis 3.26

2022-06-20 Thread Even Rouault via QGIS-Developer 
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,  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,
 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 

___
QGIS-Developer mailing list
QGIS-Developer@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@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.
___
QGIS-Developer mailing list
QGIS-Developer@lists.osgeo.org
List info: https://lists.osgeo.org/mailman/listinfo/qgis-developer
Unsubscribe: https://lists.osgeo.org/mailman/listinfo/qgis-developer

Re: [QGIS-Developer] Qgis server: terrible performance with Qgis 3.26

2022-06-20 Thread Nyall Dawson via QGIS-Developer 
On Tue, 21 June 2022, 2:48 am David Marteau,  wrote:

> 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
>

Thanks for the update! Can you fire up hotspot (or similar) and see where
the time is spent?

Nyall

>
> Le 20/06/2022 à 18:38, Nyall Dawson a écrit :
>
>
>
> On Mon, 20 June 2022, 11:42 pm David Marteau,  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@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
>>> ___
>>> QGIS-Developer mailing list
>>> QGIS-Developer@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@lists.osgeo.org
List info: https://lists.osgeo.org/mailman/listinfo/qgis-developer
Unsubscribe: https://lists.osgeo.org/mailman/listinfo/qgis-developer

Re: [QGIS-Developer] Qgis server: terrible performance with Qgis 3.26

2022-06-20 Thread David Marteau via QGIS-Developer 

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,  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,
 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 

___
QGIS-Developer mailing list
QGIS-Developer@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@lists.osgeo.org
List info: https://lists.osgeo.org/mailman/listinfo/qgis-developer
Unsubscribe: https://lists.osgeo.org/mailman/listinfo/qgis-developer

Re: [QGIS-Developer] Qgis server: terrible performance with Qgis 3.26

2022-06-20 Thread Nyall Dawson via QGIS-Developer 
On Mon, 20 June 2022, 11:42 pm David Marteau,  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@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
>> ___
>> QGIS-Developer mailing list
>> QGIS-Developer@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@lists.osgeo.org
List info: https://lists.osgeo.org/mailman/listinfo/qgis-developer
Unsubscribe: https://lists.osgeo.org/mailman/listinfo/qgis-developer

Re: [QGIS-Developer] Qgis server: terrible performance with Qgis 3.26

2022-06-20 Thread David Marteau via QGIS-Developer 

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.



Le 20/06/2022 à 15:10, Nyall Dawson a écrit :



On Mon, 20 June 2022, 9:37 pm David Marteau via QGIS-Developer, 
 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 

___
QGIS-Developer mailing list
QGIS-Developer@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@lists.osgeo.org
List info: https://lists.osgeo.org/mailman/listinfo/qgis-developer
Unsubscribe: https://lists.osgeo.org/mailman/listinfo/qgis-developer

Re: [QGIS-Developer] Qgis server: terrible performance with Qgis 3.26

2022-06-20 Thread Nyall Dawson via QGIS-Developer 
On Mon, 20 June 2022, 9:37 pm David Marteau via QGIS-Developer, <
qgis-developer@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
> ___
> QGIS-Developer mailing list
> QGIS-Developer@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@lists.osgeo.org
List info: https://lists.osgeo.org/mailman/listinfo/qgis-developer
Unsubscribe: https://lists.osgeo.org/mailman/listinfo/qgis-developer