<html>
<head>
<meta http-equiv="Content-Type" content="text/html; charset=UTF-8">
</head>
<body>
<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>I happends that loading auxiliary layer is negligible in 3.24 :</p>
<p>>> projectload, Creating auxiliary storage: 0.0 ms</p>
<p>I do not understand the difference because it appears that it
looks like the same code in 3.24 and 3.26. <br>
</p>
<p>Does compile/optimize options could have changed between release
3.24 and 3.26 ?<br>
</p>
<br>
<div class="moz-cite-prefix">Le 21/06/2022 à 14:45, David Marteau a
écrit :<br>
</div>
<blockquote type="cite"
cite="mid:a4d03745-846a-1364-e7aa-ef16c08ebd6e@3liz.com">
<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>
</blockquote>
</body>
</html>