Re: [QGIS-Developer] Profiler times in Python

[Michel Stuyts via QGIS-Developer]

Until now I always used qgis.utils.plugin_times, but I noticed the different 
values between this variable and the “Debugging/Development Tools” Panel. 
That’s the reason I wanted the profiler values.  The qgis.utils.plugin_times 
variable has 0 loading time as value for some plugins, which is also very 
unlikely.

Does anyone know the difference these two sources of plugin loading times?


Michel

Van: Etienne Trimaille 
Verzonden: vrijdag 5 mei 2023 14:03
Aan: Michel Stuyts 
CC: qgis-developer 
Onderwerp: Re: [QGIS-Developer] Profiler times in Python

U ontvangt niet vaak e-mail van 
etienne.trimai...@gmail.com<mailto:etienne.trimai...@gmail.com>. Meer 
informatie over waarom dit belangrijk 
is<https://aka.ms/LearnAboutSenderIdentification>
One line I know, maybe this is enough :

>>> from qgis.utils import plugin_times
>>> plugin_times

It's not using the profiler. Values are different from the Profiler, after a 
quick look...

Le ven. 5 mai 2023 à 10:21, Michel Stuyts via QGIS-Developer 
mailto:qgis-developer@lists.osgeo.org>> a écrit 
:
I want to use the data on plugins from the Profiler.  In the 
“Debugging/Development Tools” Panel I can see both the total time for all 
plugins and the individual time per plugin.  With the following Python code, I 
want to get the same data in Python:

profiler = QgsApplication.profiler()
for child in profiler.childGroups():
childGroup = profiler.childGroups(child)
if child == 'Load plugins':
print(child, profiler.profileTime(child))
for subGroup in childGroup:
print(subGroup, profiler.profileTime(subGroup))

It shows the total time for all plugins just fine as “Load plugins” with the 
same number of seconds as in the Panel, but for the individual plugins I get 
0.0 as time for all plugins.  What do I do wrong or is it a bug?


Michel Stuyts
___
QGIS-Developer mailing list
QGIS-Developer@lists.osgeo.org<mailto: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] Profiler times in Python

[Etienne Trimaille via QGIS-Developer]

One line I know, maybe this is enough :

>>> from qgis.utils import plugin_times
>>> plugin_times

It's not using the profiler. Values are different from the Profiler, after
a quick look...

Le ven. 5 mai 2023 à 10:21, Michel Stuyts via QGIS-Developer <
qgis-developer@lists.osgeo.org> a écrit :

> I want to use the data on plugins from the Profiler.  In the
> “Debugging/Development Tools” Panel I can see both the total time for all
> plugins and the individual time per plugin.  With the following Python
> code, I want to get the same data in Python:
>
>
>
> profiler = QgsApplication.profiler()
>
> for child in profiler.childGroups():
>
> childGroup = profiler.childGroups(child)
>
> if child == 'Load plugins':
>
> print(child, profiler.profileTime(child))
>
> for subGroup in childGroup:
>
> print(subGroup, profiler.profileTime(subGroup))
>
>
>
> It shows the total time for all plugins just fine as “Load plugins” with
> the same number of seconds as in the Panel, but for the individual plugins
> I get 0.0 as time for all plugins.  What do I do wrong or is it a bug?
>
>
>
>
>
> Michel Stuyts
> ___
> 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

[QGIS-Developer] Profiler times in Python

[Michel Stuyts via QGIS-Developer]

I want to use the data on plugins from the Profiler.  In the 
"Debugging/Development Tools" Panel I can see both the total time for all 
plugins and the individual time per plugin.  With the following Python code, I 
want to get the same data in Python:

profiler = QgsApplication.profiler()
for child in profiler.childGroups():
childGroup = profiler.childGroups(child)
if child == 'Load plugins':
print(child, profiler.profileTime(child))
for subGroup in childGroup:
print(subGroup, profiler.profileTime(subGroup))

It shows the total time for all plugins just fine as "Load plugins" with the 
same number of seconds as in the Panel, but for the individual plugins I get 
0.0 as time for all plugins.  What do I do wrong or is it a bug?


Michel Stuyts
___
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] Profiler?

[Nyall Dawson]

On Thu, 28 May 2020 at 01:39, Richard Duivenvoorde  wrote:
>
> On 5/23/20 12:41 AM, Nyall Dawson wrote:
> > It will, it's just that the Windows nightly builds are too old to have
> > it. It looks identical to your screenshot.
> >
> > On that note, 12 seconds is a long time for the plugin load I see in
> > your screenshot. Can you expand that out and see if it narrows down
> > the culprit?
>
> Ok, I've updated to QGIS nightly now on those machines.
> Note it's VM's with network disks and virusscanners... (and QGIS itself
> is on the networkdrive...)
>
> This is an image of the plugin loading times:
>
> http://duif.net/loadingtimes.png

Could you expand out those two slow plugins? (processing and lat long tools).

My suspicion is that you'll find that the lat long tools plugin is
importing some processing modules and causing them to be initialised
prior to the main processing plugin starting (which is perfectly fine,
there's no issue with doing that). I expect that if you expanded out
lat long tools you'll see that it's caught up in the processing module
imports.

But I'm keen to see the expanded view to see where the hotspots still
are and where we need to add more granular logging. (Should probably
think about adding an "export to json" option here!!)

Nyall


>
> JRodos is mine :-)
>
> Regards,
>
> Richard Duivenvoorde
>
>
___
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] Profiler?

[C Hamilton]

I don't know if it helpful or not but here are my results on QGIS 3.12 with
the Plugin Load Times plugin. This is on a Windows 10 laptop. I can cut off
a little more time with Lat Lon Tools, but not much more. It looks like I
need to optimize KML Tools.

processing: Processing 2.12.99: 1.265625s
quick_map_services: QuickMapServices 0.19.11.1: 0.703125s
kmltools: KML Tools 3.0.9: 0.406250s
profiletool: Profile tool 4.1.8: 0.265625s
latlontools: Lat Lon Tools 3.3.18: 0.203125s
MetaSearch: MetaSearch Catalog Client 0.3.5: 0.109375s
bulkgeocoder: Bulk GeoCoding 3.0.0: 0.093750s
Qgis2threejs: Qgis2threejs 2.4.2: 0.078125s
mmqgis: mmqgis 2020.1.16: 0.062500s
shapetools: Shape Tools 3.3.11: 0.062500s
FreehandRasterGeoreferencer: Freehand raster georeferencer 0.7.1: 0.046875s
PluginLoadTimes: Plugin Load Times 3.0.1: 0.031250s
MemoryLayerSaver: Memory Layer Saver 4.0.4: 0.015625s
plugin_reloader: Plugin Reloader 0.7.9: 0.015625s
searchlayers: Search Layers 3.0.1: 0.015625s
poiexport: POI Exporter 3.0.3: 0.00s
db_manager: DB Manager 0.1.20: 0.00s
TOTAL LOAD TIME: 3.375s
Calvin

On Wed, May 27, 2020 at 12:09 PM C Hamilton  wrote:

> Now you got my attention since Lat Lon Tools was one of the plugins that
> was flagged. A number of my tools are initialized when they are first used,
> but I guess I need to take a closer look at what might be slowing it down.
> Suggestions are welcome.
>
> Regards,
>
> Calvin
>
> On Wed, May 27, 2020 at 11:39 AM Richard Duivenvoorde 
> wrote:
>
>> On 5/23/20 12:41 AM, Nyall Dawson wrote:
>> > It will, it's just that the Windows nightly builds are too old to have
>> > it. It looks identical to your screenshot.
>> >
>> > On that note, 12 seconds is a long time for the plugin load I see in
>> > your screenshot. Can you expand that out and see if it narrows down
>> > the culprit?
>>
>> Ok, I've updated to QGIS nightly now on those machines.
>> Note it's VM's with network disks and virusscanners... (and QGIS itself
>> is on the networkdrive...)
>>
>> This is an image of the plugin loading times:
>>
>> http://duif.net/loadingtimes.png
>>
>> JRodos is mine :-)
>>
>> Regards,
>>
>> Richard Duivenvoorde
>>
>>
>> ___
>> 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] Profiler?

[C Hamilton]

Now you got my attention since Lat Lon Tools was one of the plugins that
was flagged. A number of my tools are initialized when they are first used,
but I guess I need to take a closer look at what might be slowing it down.
Suggestions are welcome.

Regards,

Calvin

On Wed, May 27, 2020 at 11:39 AM Richard Duivenvoorde 
wrote:

> On 5/23/20 12:41 AM, Nyall Dawson wrote:
> > It will, it's just that the Windows nightly builds are too old to have
> > it. It looks identical to your screenshot.
> >
> > On that note, 12 seconds is a long time for the plugin load I see in
> > your screenshot. Can you expand that out and see if it narrows down
> > the culprit?
>
> Ok, I've updated to QGIS nightly now on those machines.
> Note it's VM's with network disks and virusscanners... (and QGIS itself
> is on the networkdrive...)
>
> This is an image of the plugin loading times:
>
> http://duif.net/loadingtimes.png
>
> JRodos is mine :-)
>
> Regards,
>
> Richard Duivenvoorde
>
>
> ___
> 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] Profiler?

[Richard Duivenvoorde]

On 5/23/20 12:41 AM, Nyall Dawson wrote:
> It will, it's just that the Windows nightly builds are too old to have
> it. It looks identical to your screenshot.
> 
> On that note, 12 seconds is a long time for the plugin load I see in
> your screenshot. Can you expand that out and see if it narrows down
> the culprit?

Ok, I've updated to QGIS nightly now on those machines.
Note it's VM's with network disks and virusscanners... (and QGIS itself
is on the networkdrive...)

This is an image of the plugin loading times:

http://duif.net/loadingtimes.png

JRodos is mine :-)

Regards,

Richard Duivenvoorde


___
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] Profiler?

[Nyall Dawson]

On Mon, 25 May 2020 at 06:51, Sebastian M. Ernst  wrote:
>

> I'd be *very* interested in seeing something similar coming from Windows
> boxes with slow QGIS startup times. If I had to bet, I'd expect
> anomalies (i.e. high runtimes) in the CPython interpreter's module
> import mechanism.

Actually the biggest culprit seems to be parsing all the processing
grass/saga .txt description files. There's hundreds of these, and
Windows' slow file access makes reading them all very expensive.

I'm going to experiment with concatenating them all to a single file
to see if this helps...

Nyall
___
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] Profiler?

[Sebastian M. Ernst]

Hi all,

> [...]
> https://gitlab.com/GIS-projects/Plugin-Load-Times
> [...]
>
> Or the newer, more Pythonic  way:
>
>with QgsRuntimeProfiler.profile('loading something'):
>   # do some stuff
>
> I'd encourage plugin authors to use this in their plugins
> initialisation code as much as makes sense!

ah, ok - this was not *quite* what I meant.

It's actually possible to use Python's cProfile for better understanding
the *entire* QGIS Python mechanism and its issues - e.g. on startup on
"interesting" Windows deployments. I have just injected cProfile into
QGIS' startup code and visualized its output (on Linux), see here:

http://static.pleiszenburg.de/qgis/qgis_startup_cprofile.png

I'd be *very* interested in seeing something similar coming from Windows
boxes with slow QGIS startup times. If I had to bet, I'd expect
anomalies (i.e. high runtimes) in the CPython interpreter's module
import mechanism.

Best regards,
Sebastian
___
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] Profiler?

[João Gaspar]

Hi devs,
I don't know if this helps as well or is related with the Profiler subject
but Michel Stuyts share a QGIS plugin  Plugin Load Times that measures the
load time of qgis plugins (not the core but measure all the others).
More info in here:

*If QGIS takes long to start, it is probably because some of the plugins
you installed take a long time to load at startup. This plugin shows the
latest load time of each plugin (QGIS startup, plugin installation,...). It
does not give you information about the speed of plugins when they are
used. With the information provided by this plugin you can easily decide
which plugins to disable, to make QGIS start faster.*

This plugin adds a toolbar button and an item to the plugin menu to see how
long each plugin loads in QGIS 3. It shows the QGIS python variable
*qgis.utils.plugin_times
*
in an easy to understand window. It's possible to sort the results based on
plugin name or on load time. In the latest version it also has a pie chart
with the data visualized.

Some core plugins are not available in the QGIS Python Variable, so they
will not be shown in this plugin. For the following core plugins no
information about the load time is available in "Plugin Load Times":

   - Coordinate Capture
   - eViz
   - Geometry Checker
   - Georeferencer GDAL
   - GPS Tools
   - GRASS 7
   - OfflineEditing
   - Topology Checker



https://gitlab.com/GIS-projects/Plugin-Load-Times

Search in plugin manager for Plugin Load Times or

https://plugins.qgis.org/plugins/PluginLoadTimes/

Cheers,
João Gaspar


Nyall Dawson  escreveu no dia domingo, 24/05/2020
à(s) 10:29:

> On Sat, 23 May 2020 at 22:19, Nathan Woodrow  wrote:
> >
> > Correct. QgsRuntimeProfiler is the tool that can do it.
> >
> > https://qgis.org/api/classQgsRuntimeProfiler.html
> >
> > In Python you can access it using this:
> >
> >  QgsApplication.instance().profiler()
> >
> > An example:
> >
> >QgsApplication.instance().profiler().start("my_thing")
> > # long expensive stuff
> >  QgsApplication.instance().profiler().end()
>
>
> Or the newer, more Pythonic  way:
>
>with QgsRuntimeProfiler.profile('loading something'):
>   # do some stuff
>
> I'd encourage plugin authors to use this in their plugins
> initialisation code as much as makes sense!
>
> Nyall
>
> >
> >
> >
> > On Sat, May 23, 2020 at 9:38 PM Richard Duivenvoorde <
> rdmaili...@duif.net> wrote:
> >>
> >> On 5/23/20 11:42 AM, Sebastian M. Ernst wrote:
> >>
> >> > @Richard How does your Citrix setup / architecture look like
> >> > (approximately)?
> >>
> >> I'll ask around for more details, as I'm there just as a user of that
> setup.
> >>
> >> But I did try a lot of things: and exactly what you tell: their virus
> >> scanner was pushing some hash version of all python files to some online
> >> service. So I disabled it...
> >> But still... And off course they are working with some network shares,
> >> so I will try out some of your other idea's
> >>
> >> > @Nathan & @Nyall Where in QGIS' source can I find the profiling tool?
> I
> >> > just searched and could not locate it ... Would you consider adding
> >> > support for a Python profiler to it, e.g. [1], [2] or [3]? The
> relevant
> >> > code could (conditionally) be injected somewhere around here [4] or
> here
> >> > [5]. I have played with this idea a while ago. It works in principle,
> >> > but a proper integration into your GUI would be great ...
> >>
> >> In my debug build, using
> >> export QGIS_DEBUG=5
> >>
> >> I see:
> >>
> >> ../src/core/symbology/qgssymbollayerutils.cpp:3936 :
> >> (svgSymbolNameToPath) [0ms] Svg found in alternative path
> >> ../src/core/qgsruntimeprofiler.cpp:80 : (end) [0ms] PROFILE: Load
> >> default style database/Load symbols/topo camp - 0.001
> >> ../src/core/qgsruntimeprofiler.cpp:80 : (end) [0ms] PROFILE: Load
> >> default style database/Load symbols/topo foot - 0
> >> ../src/core/qgsruntimeprofiler.cpp:80 : (end) [0ms] PROFILE: Load
> >> default style database/Load symbols/topo forest - 0
> >>
> >> So:
> >>
> https://github.com/qgis/QGIS/blob/master/src/core/qgsruntimeprofiler.cpp
> :-)
> >>
> >> Regards,
> >>
> >> Richard Duivenvoorde
> >> ___
> >> 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
> ___
> QGIS-Developer mailing list
> QGIS-Developer@lists.osgeo.org
> List info: https://lists.osgeo.org/mailman/listinfo/qgis-developer
> Unsubscribe: 

Re: [QGIS-Developer] Profiler?

[Nyall Dawson]

On Sat, 23 May 2020 at 22:19, Nathan Woodrow  wrote:
>
> Correct. QgsRuntimeProfiler is the tool that can do it.
>
> https://qgis.org/api/classQgsRuntimeProfiler.html
>
> In Python you can access it using this:
>
>  QgsApplication.instance().profiler()
>
> An example:
>
>QgsApplication.instance().profiler().start("my_thing")
> # long expensive stuff
>  QgsApplication.instance().profiler().end()


Or the newer, more Pythonic  way:

   with QgsRuntimeProfiler.profile('loading something'):
  # do some stuff

I'd encourage plugin authors to use this in their plugins
initialisation code as much as makes sense!

Nyall

>
>
>
> On Sat, May 23, 2020 at 9:38 PM Richard Duivenvoorde  
> wrote:
>>
>> On 5/23/20 11:42 AM, Sebastian M. Ernst wrote:
>>
>> > @Richard How does your Citrix setup / architecture look like
>> > (approximately)?
>>
>> I'll ask around for more details, as I'm there just as a user of that setup.
>>
>> But I did try a lot of things: and exactly what you tell: their virus
>> scanner was pushing some hash version of all python files to some online
>> service. So I disabled it...
>> But still... And off course they are working with some network shares,
>> so I will try out some of your other idea's
>>
>> > @Nathan & @Nyall Where in QGIS' source can I find the profiling tool? I
>> > just searched and could not locate it ... Would you consider adding
>> > support for a Python profiler to it, e.g. [1], [2] or [3]? The relevant
>> > code could (conditionally) be injected somewhere around here [4] or here
>> > [5]. I have played with this idea a while ago. It works in principle,
>> > but a proper integration into your GUI would be great ...
>>
>> In my debug build, using
>> export QGIS_DEBUG=5
>>
>> I see:
>>
>> ../src/core/symbology/qgssymbollayerutils.cpp:3936 :
>> (svgSymbolNameToPath) [0ms] Svg found in alternative path
>> ../src/core/qgsruntimeprofiler.cpp:80 : (end) [0ms] PROFILE: Load
>> default style database/Load symbols/topo camp - 0.001
>> ../src/core/qgsruntimeprofiler.cpp:80 : (end) [0ms] PROFILE: Load
>> default style database/Load symbols/topo foot - 0
>> ../src/core/qgsruntimeprofiler.cpp:80 : (end) [0ms] PROFILE: Load
>> default style database/Load symbols/topo forest - 0
>>
>> So:
>> https://github.com/qgis/QGIS/blob/master/src/core/qgsruntimeprofiler.cpp :-)
>>
>> Regards,
>>
>> Richard Duivenvoorde
>> ___
>> 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
___
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] Profiler?

[Régis Haubourg]

Le sam. 23 mai 2020 à 00:42, Nyall Dawson  a écrit :

> On Fri, 22 May 2020 at 20:01, Richard Duivenvoorde 
> wrote:
> [..]
> > I do have an issue with long startup times on Windows at a client
> > working with a cytrix setup (though I guess it is a general
> > python/startup issue there),
>
> This is EXACTLY the kind of issue this was added for! I also see
> occasional 5 minute+ startup times on Windows (bare metal installs)
> and would like to get this resolved for 3.14. (It's a bad experience
> for users, and when things are working correctly QGIS should startup
> in a couple of seconds at most. Our (usual) speedy startup is
> something which differentiates us from a certain other desktop GIS
> application ;)
>
>
Hi, this is great!

I reopened this very long standing issue (5 years) of windows slow startup
phenomenon: https://github.com/qgis/QGIS/issues/20061

regards
Régis



> >
> > Regards,
> >
> > Richard Duivenvoorde
> > ___
> > 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
___
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] Profiler?

[Nathan Woodrow]

Correct. QgsRuntimeProfiler is the tool that can do it.

https://qgis.org/api/classQgsRuntimeProfiler.html

In Python you can access it using this:

 QgsApplication.instance().profiler()

An example:

   QgsApplication.instance().profiler().start("my_thing")
# long expensive stuff
 QgsApplication.instance().profiler().end()



On Sat, May 23, 2020 at 9:38 PM Richard Duivenvoorde 
wrote:

> On 5/23/20 11:42 AM, Sebastian M. Ernst wrote:
>
> > @Richard How does your Citrix setup / architecture look like
> > (approximately)?
>
> I'll ask around for more details, as I'm there just as a user of that
> setup.
>
> But I did try a lot of things: and exactly what you tell: their virus
> scanner was pushing some hash version of all python files to some online
> service. So I disabled it...
> But still... And off course they are working with some network shares,
> so I will try out some of your other idea's
>
> > @Nathan & @Nyall Where in QGIS' source can I find the profiling tool? I
> > just searched and could not locate it ... Would you consider adding
> > support for a Python profiler to it, e.g. [1], [2] or [3]? The relevant
> > code could (conditionally) be injected somewhere around here [4] or here
> > [5]. I have played with this idea a while ago. It works in principle,
> > but a proper integration into your GUI would be great ...
>
> In my debug build, using
> export QGIS_DEBUG=5
>
> I see:
>
> ../src/core/symbology/qgssymbollayerutils.cpp:3936 :
> (svgSymbolNameToPath) [0ms] Svg found in alternative path
> ../src/core/qgsruntimeprofiler.cpp:80 : (end) [0ms] PROFILE: Load
> default style database/Load symbols/topo camp - 0.001
> ../src/core/qgsruntimeprofiler.cpp:80 : (end) [0ms] PROFILE: Load
> default style database/Load symbols/topo foot - 0
> ../src/core/qgsruntimeprofiler.cpp:80 : (end) [0ms] PROFILE: Load
> default style database/Load symbols/topo forest - 0
>
> So:
> https://github.com/qgis/QGIS/blob/master/src/core/qgsruntimeprofiler.cpp
> :-)
>
> Regards,
>
> Richard Duivenvoorde
> ___
> 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] Profiler?

[Richard Duivenvoorde]

On 5/23/20 11:42 AM, Sebastian M. Ernst wrote:

> @Richard How does your Citrix setup / architecture look like
> (approximately)?

I'll ask around for more details, as I'm there just as a user of that setup.

But I did try a lot of things: and exactly what you tell: their virus
scanner was pushing some hash version of all python files to some online
service. So I disabled it...
But still... And off course they are working with some network shares,
so I will try out some of your other idea's

> @Nathan & @Nyall Where in QGIS' source can I find the profiling tool? I
> just searched and could not locate it ... Would you consider adding
> support for a Python profiler to it, e.g. [1], [2] or [3]? The relevant
> code could (conditionally) be injected somewhere around here [4] or here
> [5]. I have played with this idea a while ago. It works in principle,
> but a proper integration into your GUI would be great ...

In my debug build, using
export QGIS_DEBUG=5

I see:

../src/core/symbology/qgssymbollayerutils.cpp:3936 :
(svgSymbolNameToPath) [0ms] Svg found in alternative path
../src/core/qgsruntimeprofiler.cpp:80 : (end) [0ms] PROFILE: Load
default style database/Load symbols/topo camp - 0.001
../src/core/qgsruntimeprofiler.cpp:80 : (end) [0ms] PROFILE: Load
default style database/Load symbols/topo foot - 0
../src/core/qgsruntimeprofiler.cpp:80 : (end) [0ms] PROFILE: Load
default style database/Load symbols/topo forest - 0

So:
https://github.com/qgis/QGIS/blob/master/src/core/qgsruntimeprofiler.cpp :-)

Regards,

Richard Duivenvoorde
___
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] Profiler?

[Sebastian M. Ernst]

Hi Nyall, Richard, Nathan,

> Yeah! Full credit goes to Nathan Woodrow here, this panel just exposes
> a profiling tool he added a while back.

I did not know that. Amazing tool.

>> I do have an issue with long startup times on Windows at a client
>> working with a cytrix setup (though I guess it is a general
>> python/startup issue there),
> 
> This is EXACTLY the kind of issue this was added for! I also see
> occasional 5 minute+ startup times on Windows (bare metal installs)

@Richard How does your Citrix setup / architecture look like
(approximately)?

@Nyall If this has anything to do with Python stuff - and it probably
might - can you elaborate on the kind of bare metal setups where you are
observing this?

I am troubleshooting "pure" (i.e. unrelated to QGIS) Python setups for
clients on their Windows boxes on a regular basis. There are multiply
typical culprits for slow load/import times. My #1 favorite is a certain
"security software" typically found in large deployments, but it is a
problem that applies to most "security tools" with varying degrees of
slowdowns. #2 on the list is a mix of NTFS-related issues (rights
management, shadow copies). #1 can usually be identified by
(temporarily) deactivating online scanning of every accessed file. In
some cases, you can only rule it out by deactivating the entire
"security" tool *and* re-installing Python (QGIS in your case) - because
the "security" stuff digs itself deep into the import mechanism. In some
cases you can actually observe changed hash sums of critical Python
libraries ... #2 can be ruled out by installing the entire stack with
*minimal* user rights only (really, really important) onto a clean NTFS
partition / disk without shadow copies. You might not be able to run a
setup.exe with user rights depending on the system configuration -
you'll then have to work around by copying an existing installation into
a user's directory (followed by manually adjusting configurations,
paths, rights and owners). #3 on the list is (SMB/CIFS) network shares.
If your (Python) software is running from there, your best (bad) option
is playing with the buffer configuration of this mechanism, which
usually is not an option in large deployments. Your second best (bad)
option is deactivating the scanning of network traffic in the "security"
tool.

> On that note, 12 seconds is a long time for the plugin load I see in
> your screenshot. Can you expand that out and see if it narrows down
> the culprit?

I'd add that I would also like to understand why loading just the Python
support itself requires 1.5 seconds.

@Nathan & @Nyall Where in QGIS' source can I find the profiling tool? I
just searched and could not locate it ... Would you consider adding
support for a Python profiler to it, e.g. [1], [2] or [3]? The relevant
code could (conditionally) be injected somewhere around here [4] or here
[5]. I have played with this idea a while ago. It works in principle,
but a proper integration into your GUI would be great ...

Best regards,
Sebastian


[1] https://docs.python.org/3/library/profile.html
[2] https://github.com/vpelletier/pprofile
[3] https://github.com/pyutils/line_profiler
[4]
https://github.com/qgis/QGIS/blob/42ba3d78febd5ae9833edc55eac060148c1e0522/src/python/qgspythonutilsimpl.cpp#L208
[5]
https://github.com/qgis/QGIS/blob/42ba3d78febd5ae9833edc55eac060148c1e0522/src/python/qgspythonutilsimpl.cpp#L51
___
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] Profiler?

[Richard Duivenvoorde]

On 5/23/20 12:41 AM, Nyall Dawson wrote:
>> I do have an issue with long startup times on Windows at a client
>> working with a cytrix setup (though I guess it is a general
>> python/startup issue there),
> This is EXACTLY the kind of issue this was added for! I also see
> occasional 5 minute+ startup times on Windows (bare metal installs)
> and would like to get this resolved for 3.14. (It's a bad experience
> for users, and when things are working correctly QGIS should startup
> in a couple of seconds at most. Our (usual) speedy startup is
> something which differentiates us from a certain other desktop GIS
> application ;)
> 
>> but was wondering if this would come to the
>> Windows world too... (technically different?)?
> It will, it's just that the Windows nightly builds are too old to have
> it. It looks identical to your screenshot.
> 
> On that note, 12 seconds is a long time for the plugin load I see in
> your screenshot. Can you expand that out and see if it narrows down
> the culprit?

Do not worry about that one, that was QGIS starting up during my
'make -j8' build of QGIS master :-)

As said on Linux startup times are just much better.

I will wait for this profiler to show up in windows and report back...

Thanks all!

Richar
___
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] Profiler?

[Nyall Dawson]

On Fri, 22 May 2020 at 20:01, Richard Duivenvoorde  wrote:
>
> Hi Devs,
>
> I happen to see a little 'clock' tab in the 'dev tools' in master on
> Debian, and see it is some kind of startup profiler...?
> The dev tols are getting better and better :-)

Yeah! Full credit goes to Nathan Woodrow here, this panel just exposes
a profiling tool he added a while back.

> I do have an issue with long startup times on Windows at a client
> working with a cytrix setup (though I guess it is a general
> python/startup issue there),

This is EXACTLY the kind of issue this was added for! I also see
occasional 5 minute+ startup times on Windows (bare metal installs)
and would like to get this resolved for 3.14. (It's a bad experience
for users, and when things are working correctly QGIS should startup
in a couple of seconds at most. Our (usual) speedy startup is
something which differentiates us from a certain other desktop GIS
application ;)

> but was wondering if this would come to the
> Windows world too... (technically different?)?

It will, it's just that the Windows nightly builds are too old to have
it. It looks identical to your screenshot.

On that note, 12 seconds is a long time for the plugin load I see in
your screenshot. Can you expand that out and see if it narrows down
the culprit?

Nyall


>
> To be honest I never had issues on Linux, but that is a rather beefy dev
> laptop...
>
> Regards,
>
> Richard Duivenvoorde
> ___
> 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

[QGIS-Developer] Profiler?

[Richard Duivenvoorde]

Hi Devs,

I happen to see a little 'clock' tab in the 'dev tools' in master on
Debian, and see it is some kind of startup profiler...?
The dev tols are getting better and better :-)

I do have an issue with long startup times on Windows at a client
working with a cytrix setup (though I guess it is a general
python/startup issue there), but was wondering if this would come to the
Windows world too... (technically different?)?

To be honest I never had issues on Linux, but that is a rather beefy dev
laptop...

Regards,

Richard Duivenvoorde
___
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