<html>
<head>
<meta http-equiv="Content-Type" content="text/html; charset=UTF-8">
</head>
<body>
<p>Hi,<br>
</p>
<p>Here is a first analysis using QgsRuntimeProfiler outputs</p>
<p>The project is the same in all tests and has been saved with Qgis
3.26. <br>
This is a first load in each case just after qgis init, so there
should be no caching involved.</p>
<p>Output has been filtered to `projectload` profiler group and rows
with elapsed time > 0 <br>
</p>
<p>All builds are official builds and installed from qgis.org
packages. <br>
Tests are run in Docker container with ubuntu 21.04<br>
</p>
<p>Total time show a variance of +/- 25% on multiple runs.</p>
<p>## Qgis 3.26<br>
<br>
### Flags<br>
* Qgis.ProjectReadFlag.TrustLayerMetadata<br>
* Qgis.ProjectReadFlag.DontLoad3DViews<br>
* Qgis.ProjectReadFlag.DontLoadProjectStyles<br>
</p>
<p>projectload, Reading project file: 21.0 ms<br>
projectload, Creating auxiliary storage: 65.0 ms<br>
projectload, Reading properties: 19.0 ms<br>
projectload, Reading map layers: 14.0 ms<br>
-projectload, france_parts: 6.0 ms<br>
--projectload, Load layer source: 5.0 ms<br>
---projectload, Create ogr provider: 3.0 ms<br>
-projectload, france_parts bordure: 4.0 ms<br>
--projectload, Load layer source: 4.0 ms<br>
---projectload, Create ogr provider: 2.0 ms<br>
-projectload, france_parts tuilé en cache: 3.0 ms<br>
--projectload, Load layer source: 3.0 ms<br>
---projectload, Create ogr provider: 1.0 ms<br>
projectload, Storing original layer properties: 2.0 ms</p>
<p>Total time: 152.0 ms<br>
</p>
<p>## Qgis 3.24</p>
<p>### Flags<br>
* QgsProject.FlagTrustLayerMetadata<br>
<br>
projectload, Reading project file: 5.0 ms<br>
projectload, Reading properties: 4.0 ms<br>
projectload, Reading map layers: 4.0 ms<br>
-projectload, france_parts: 1.0 ms<br>
--projectload, Load layer source: 1.0 ms<br>
-projectload, france_parts bordure: 1.0 ms<br>
--projectload, Load layer source: 1.0 ms<br>
-projectload, france_parts tuilé en cache: 1.0 ms<br>
--projectload, Load layer source: 1.0 ms<br>
projectload, Storing original layer properties: 1.0 ms<br>
projectload, Updating interface: 1.0 ms<br>
</p>
<p>Total time: 21.0 ms</p>
<p>Some remarks:<br>
</p>
<p>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:<br>
I need to figure how auxiliary layers are loaded in Qgis 3.24 (are
they loaded lazily ?).</p>
<p>The `Reading project file`, `Reading properties` and `Reading map
layers` sections are almost 3 to 4 times slower in Qgis 3.26.</p>
<p>The loading of layers ares also slower in Qgis 3.26 compared to
Qgis 3.24.</p>
<p> <br>
</p>
<div class="moz-cite-prefix">Le 21/06/2022 à 12:27, David Marteau a
écrit :<br>
</div>
<blockquote type="cite"
cite="mid:6d227afe-7b69-f3b0-db2f-76af51d85dbc@3liz.com">
<p><br>
</p>
<p>May be I could use QgsRuntimeProfiler output in first place ? <br>
</p>
Le 20/06/2022 à 18:55, Even Rouault a écrit :<br>
<blockquote type="cite"
cite="mid:f1ae0fc1-5ad0-34d7-55e0-e084a12bb61d@spatialys.com">
<p>Use sysprof or just run under a debugger and interrupt
regularly should help you spot in which method(s) most time is
spent<br>
</p>
<div class="moz-cite-prefix">Le 20/06/2022 à 18:48, David
Marteau via QGIS-Developer a écrit :<br>
</div>
<blockquote type="cite"
cite="mid:5a055779-8982-ff06-0921-b3d495e48b84@3liz.com">
<p>I used the following test:<br>
</p>
<div class="inner_cell">
<div class="input_area" aria-label="Edit code here">
<div class="CodeMirror cm-s-ipython">
<div><textarea spellcheck="false" tabindex="0" wrap="off"></textarea></div>
<div class="CodeMirror-scroll" tabindex="-1"
draggable="true">
<div class="CodeMirror-sizer">
<div>
<div class="CodeMirror-lines" role="presentation">
<div role="presentation">
<div class="CodeMirror-code"
role="presentation">
<pre><span role="presentation"><span class="cm-variable">readflags</span> <span class="cm-operator">=</span> <span class="cm-variable">Qgis</span>.<span class="cm-property">ProjectReadFlags</span>()
<span class="cm-variable">readflags</span> <span class="cm-operator">|=</span> <span class="cm-variable">Qgis</span>.<span class="cm-property">ProjectReadFlag</span>.<span class="cm-property">TrustLayerMetadata</span><span class="cm-operator">|</span><span class="cm-variable">Qgis</span>.<span class="cm-property">ProjectReadFlag</span>.<span class="cm-property">DontLoad3DViews</span><span class="cm-operator">|</span><span class="cm-variable">Qgis</span>.<span class="cm-property">ProjectReadFlag</span>.<span class="cm-property">DontLoadProjectStyles
</span><span class="cm-variable">
prj</span> <span class="cm-operator">=</span> <span class="cm-variable">QgsProject</span>()<span class="cm-operator">
%</span><span class="cm-variable">timeit</span> <span class="cm-operator">-</span><span class="cm-variable">n</span> <span class="cm-number">1</span> <span class="cm-variable">prj</span>.<span class="cm-property">read</span>(<span class="cm-string">f"</span>{<span class="cm-variable">datapath</span>}<span class="cm-string">/france_parts3_26.qgs"</span>,<span class="cm-variable">readflags</span>)</span>
105 ms ± 18.5 ms per loop (mean ± std. dev. of 7 runs, 1 loop each)
</pre>
</div>
</div>
</div>
</div>
</div>
</div>
</div>
</div>
</div>
<p>This improve the result but we are still much higher that
the loading time of 3.24: 15ms compared to 105ms<br>
</p>
<p><br>
</p>
<div class="moz-cite-prefix">Le 20/06/2022 à 18:38, Nyall
Dawson a écrit :<br>
</div>
<blockquote type="cite"
cite="mid:CAB28AshtyQst8fRFxuhBzicDi=+Lhqy6oBxPoCtgfavhs9e+CQ@mail.gmail.com">
<div dir="auto">
<div><br>
<br>
<div class="gmail_quote">
<div dir="ltr" class="gmail_attr">On Mon, 20 June
2022, 11:42 pm David Marteau, <<a
href="mailto:dmarteau@3liz.com"
class="moz-txt-link-freetext"
moz-do-not-send="true">dmarteau@3liz.com</a>>
wrote:<br>
</div>
<blockquote class="gmail_quote">
<div>
<p>Hi,</p>
<div dir="auto">> You should set the other new
read optimisation flags here -- see <a
href="https://github.com/qgis/QGIS/blob/88ebb3f2f513dbce5a775f50e51ea0117f859c65/src/core/qgis.h#L1962"
target="_blank" rel="noreferrer"
class="moz-txt-link-freetext"
moz-do-not-send="true">https://github.com/qgis/QGIS/blob/88ebb3f2f513dbce5a775f50e51ea0117f859c65/src/core/qgis.h#L1962</a></div>
<div dir="auto"><br>
</div>
<div dir="auto">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 ).</div>
<div dir="auto"><br>
</div>
<div dir="auto">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.<br>
</div>
</div>
</blockquote>
</div>
</div>
<div dir="auto"><br>
</div>
<div dir="auto">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.</div>
<div dir="auto"><br>
</div>
<div dir="auto">Nyall</div>
<div dir="auto">
<div class="gmail_quote">
<blockquote class="gmail_quote">
<div>
<div dir="auto"> </div>
<div dir="auto"><br>
</div>
<div dir="auto"><br>
</div>
Le 20/06/2022 à 15:10, Nyall Dawson a écrit :<br>
<blockquote type="cite">
<div dir="auto">
<div><br>
<br>
<div class="gmail_quote">
<div dir="ltr" class="gmail_attr">On Mon,
20 June 2022, 9:37 pm David Marteau via
QGIS-Developer, <<a
href="mailto:qgis-developer@lists.osgeo.org"
target="_blank" rel="noreferrer"
class="moz-txt-link-freetext"
moz-do-not-send="true">qgis-developer@lists.osgeo.org</a>>
wrote:<br>
</div>
<blockquote class="gmail_quote">
<div>
<p>Hi,</p>
<p>I have noticed a huge drop of
performance while testing Qgis
server with Qgis 3.26, from 10x to
30x slower as usual.</p>
<p>Trying to reduce the problem I have
found a huge increase of time spend
reading the project in 3.26 compared
to 3.24.</p>
<p>Here some benchmark with very
simple project from the test data
set. Note: the project has been
updated with qgis 3.26:</p>
<p>Qgis 3.24:<br>
======<br>
</p>
<div>
<div aria-label="Edit code here">
<div>
<div><textarea></textarea></div>
<div>
<div>
<div>
<div role="presentation">
<div role="presentation">
<div
role="presentation">
<pre role="presentation"><span role="presentation"><span>readflags</span> <span>=</span> <span>QgsProject</span>.<span>ReadFlags</span>()<span>
readflags</span> <span>|=</span> <span>QgsProject</span>.<span>FlagTrustLayerMetadata</span></span></pre>
<pre role="presentation"><span role="presentation"><span></span><span>prj</span> <span>=</span> <span>QgsProject</span>()</span></pre>
<pre role="presentation"><span role="presentation"><span>%</span><span>timeit</span> <span>-</span><span>n</span> <span>1</span> <span>prj</span>.<span>read</span>(<span>f"</span>{<span>datapath</span>}<span>/france_parts.qgs"</span>,<span>readflags</span>)</span></pre>
</div>
</div>
</div>
</div>
</div>
</div>
</div>
</div>
</div>
<div dir="auto">
<pre>> 15.7 ms ± 205 µs per loop (mean ± std. dev. of 7 runs, 1 loop each)
</pre>
</div>
<p>Qgis 3.26:<br>
======</p>
<div role="presentation">
<pre role="presentation"><span role="presentation"><span>readflags</span> <span>=</span> <span>QgsProject</span>.<span>ReadFlags</span>()
<span>readflags</span> <span>|=</span> <span>QgsProject</span>.<span>FlagTrustLayerMetadata</span></span></pre>
</div>
</div>
</blockquote>
</div>
</div>
<div dir="auto"><br>
</div>
<div dir="auto">You should set the other new
read optimisation flags here -- see <a
href="https://github.com/qgis/QGIS/blob/88ebb3f2f513dbce5a775f50e51ea0117f859c65/src/core/qgis.h#L1962"
target="_blank" rel="noreferrer"
class="moz-txt-link-freetext"
moz-do-not-send="true">https://github.com/qgis/QGIS/blob/88ebb3f2f513dbce5a775f50e51ea0117f859c65/src/core/qgis.h#L1962</a></div>
<div dir="auto"><br>
</div>
<div dir="auto">Nyall</div>
<div dir="auto"><br>
</div>
<div dir="auto">
<div class="gmail_quote">
<blockquote class="gmail_quote">
<div>
<div role="presentation">
<pre role="presentation"><span role="presentation"><span></span><span>prj</span> <span>=</span> <span>QgsProject</span>()</span></pre>
<pre role="presentation"><span role="presentation"><span>%</span><span>timeit</span> <span>-</span><span>n</span> <span>1</span> <span>prj</span>.<span>read</span>(<span>f"</span>{<span>datapath</span>}<span>/france_parts.qgs"</span>,<span>readflags</span>)</span></pre>
</div>
<div dir="auto">
<pre>195 ms ± 44 ms per loop (mean ± std. dev. of 7 runs, 1 loop each)
</pre>
<p>There is a factor x10 between
Qgis 3.24 et Qgis 3.26 for the
exact same project. <br>
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.</p>
<br>
</div>
<div>
<p> <span>David Marteau</span> <br>
<a href="http://www.3liz.com"
rel="noreferrer noreferrer"
target="_blank"
moz-do-not-send="true">www.3liz.com</a>
<br>
<span> </span> </p>
</div>
</div>
_______________________________________________<br>
QGIS-Developer mailing list<br>
<a
href="mailto:QGIS-Developer@lists.osgeo.org"
rel="noreferrer noreferrer"
target="_blank"
class="moz-txt-link-freetext"
moz-do-not-send="true">QGIS-Developer@lists.osgeo.org</a><br>
List info: <a
href="https://lists.osgeo.org/mailman/listinfo/qgis-developer"
rel="noreferrer noreferrer noreferrer"
target="_blank"
class="moz-txt-link-freetext"
moz-do-not-send="true">https://lists.osgeo.org/mailman/listinfo/qgis-developer</a><br>
Unsubscribe: <a
href="https://lists.osgeo.org/mailman/listinfo/qgis-developer"
rel="noreferrer noreferrer noreferrer"
target="_blank"
class="moz-txt-link-freetext"
moz-do-not-send="true">https://lists.osgeo.org/mailman/listinfo/qgis-developer</a><br>
</blockquote>
</div>
</div>
</div>
</blockquote>
</div>
</blockquote>
</div>
</div>
</div>
</blockquote>
<br>
<fieldset class="moz-mime-attachment-header"></fieldset>
<pre class="moz-quote-pre" wrap="">_______________________________________________
QGIS-Developer mailing list
<a class="moz-txt-link-abbreviated moz-txt-link-freetext" href="mailto:QGIS-Developer@lists.osgeo.org" moz-do-not-send="true">QGIS-Developer@lists.osgeo.org</a>
List info: <a class="moz-txt-link-freetext" href="https://lists.osgeo.org/mailman/listinfo/qgis-developer" moz-do-not-send="true">https://lists.osgeo.org/mailman/listinfo/qgis-developer</a>
Unsubscribe: <a class="moz-txt-link-freetext" href="https://lists.osgeo.org/mailman/listinfo/qgis-developer" moz-do-not-send="true">https://lists.osgeo.org/mailman/listinfo/qgis-developer</a>
</pre>
</blockquote>
<pre class="moz-signature" cols="72">--
<a class="moz-txt-link-freetext" href="http://www.spatialys.com" moz-do-not-send="true">http://www.spatialys.com</a>
My software is free, but my time generally not.</pre>
</blockquote>
</blockquote>
</body>
</html>