<div dir="ltr"><div dir="ltr"><div dir="ltr"><div>Hi Panos and Markus,</div><div><br></div><div>I actually touched on this in my master's thesis [1, p. 54-58], specifically on the subprocess call overhead (i.e. not import or initialization overheads). I compared speed of calling subprocess in Python to a Python function call. The reason was that I was calling GRASS modules many times for small portions of my computational region, i.e. I was changing region always to the area/object of interest within the actual (user set) computational region. So, the overall process involved actually many subprocess calls depending on the size of data. Unfortunately, I don't have there a comparison of how the two cases (functions versus subprocesses) would look like in terms of time spend for the whole process.<br></div><div><br></div>And speaking more generally, it seems to me that the functionality-CLI coupling issue is what might me be partially fueling Facundo's GSoC proposal (Python package for topology tools). There access to functionality does not seem direct enough to the user-programmer with overhead of subprocess call as well as related I/O cost, whether real or perceived, playing a role.<br><div><br></div><div>Best,<br></div><div>Vaclav<br></div><div dir="ltr"><br></div><div dir="ltr">[1] Petras V. 2013. Building detection from aerial images in GRASS GIS environment. Master’s thesis. Czech Technical University in Prague. <a href="http://geo.fsv.cvut.cz/proj/dp/2013/vaclav-petras-dp-2013.pdf" target="_blank">http://geo.fsv.cvut.cz/proj/dp/2013/vaclav-petras-dp-2013.pdf</a><br></div></div><div dir="ltr"><br></div><div dir="ltr"></div><div dir="ltr"><br><div class="gmail_quote"><div dir="ltr" class="gmail_attr">On Wed, May 1, 2019 at 6:03 PM Markus Metz <<a href="mailto:markus.metz.giswork@gmail.com" target="_blank">markus.metz.giswork@gmail.com</a>> wrote:<br></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"><div dir="ltr"><div>Hi Panos,</div><div><br></div><div>IMHO the overhead of calling GRASS modules is insignificant because it is in the range of milliseconds. I am much more concerned whether executing a GRASS module takes days or hours or minutes.</div><div><br></div><div>Also note that the base of GRASS are C modules using the GRASS C library. GRASS python modules usually call GRASS C modules (or other GRASS python modules calling GRASS C modules). The first thing a GRASS Python module does is calling the GRASS C module g.parser, after that it calls (in the end) some other GRASS C modules. That means it is not straightforward to test the overhead of calling GRASS Python modules vs calling GRASS C modules because it is really GRASS Python + C modules vs GRASS C modules only. And the overhead is insignificant (not measurable) compared to actual execution time for larger datasets/regions.</div><div><br></div><div>Markus M</div><div><br></div></div><br><div class="gmail_quote"><div dir="ltr" class="gmail_attr">On Mon, Apr 29, 2019 at 8:49 AM Panagiotis Mavrogiorgos <<a href="mailto:pmav99@gmail.com" target="_blank">pmav99@gmail.com</a>> wrote:<br></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"><div dir="ltr"><div dir="ltr">Hello all<div><br></div><div>You might find it easier to read the following text <a href="https://gist.github.com/pmav99/8f4546fe15940b3cb7db0cfb65e18d33" target="_blank">i</a>n a <a href="https://gist.github.com/pmav99/8f4546fe15940b3cb7db0cfb65e18d33" target="_blank">gist</a></div><div><br></div><div><div><font face="monospace, monospace">## Introduction</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">I was trying to write a decorator/contextmanager that would temporary change the</font></div><div><font face="monospace, monospace">computational region, but while using it I noticed that there was some overhead the root</font></div><div><font face="monospace, monospace">of which seemed to be the usage of the GRASS modules. So in order to quantify this</font></div><div><font face="monospace, monospace">I wrote a small benchmark that tries to measure the overhead of calling a GRASS Module.</font></div><div><font face="monospace, monospace">This is what I found.</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">## tl;dr</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">Calling a GRASS module incurs a constant but measurable overhead which, in certain</font></div><div><font face="monospace, monospace">cases, e.g. when writing a module that uses a lot of the other modules, can quickly</font></div><div><font face="monospace, monospace">add up to a significant quantity.</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">## Disclaimer</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">If you try to run the benchmark on your own PC, the actual timings you will get will</font></div><div><font face="monospace, monospace">probably be different. The differences might be caused by having:</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">- a stronger/weaker CPU</font></div><div><font face="monospace, monospace">- faster/slower hard disk.</font></div><div><font face="monospace, monospace">- using different Python version</font></div><div><font face="monospace, monospace">- using different compilation flags</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">Still, I think that some of the findings are reproducible.</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">For reference, I used:</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">- OS: Linux 5.0.9</font></div><div><font face="monospace, monospace">- CPU: Intel i7 6700HQ</font></div><div><font face="monospace, monospace">- Disk type: SSD</font></div><div><font face="monospace, monospace">- Python: 3.7</font></div><div><font face="monospace, monospace">- `CFLAGS='-O2 -fPIC -march=native -std=gnu99'`</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">## Demonstration</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">The easiest way to demonstrate the performance difference between using a GRASS module</font></div><div><font face="monospace, monospace">vs using the GRASS API is to run the following snippets.</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">Both of them do exactly the same thing, i.e. retrieve the current region settings 10</font></div><div><font face="monospace, monospace">times in a row. The performance difference is huge though. On my laptop, the first one</font></div><div><font face="monospace, monospace">needs 0.36 seconds while the second one needs just 0.00038 seconds. That's almost</font></div><div><font face="monospace, monospace">a 1000x difference...</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">``` python</font></div><div><font face="monospace, monospace">import time</font></div><div><font face="monospace, monospace">import grass.script as gscript</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">start = time.time()</font></div><div><font face="monospace, monospace">for i in range(10):</font></div><div><font face="monospace, monospace"> region = gscript.parse_command("g.region", flags="g")</font></div><div><font face="monospace, monospace">end = time.time()</font></div><div><font face="monospace, monospace">total = end - start</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">print("Total time: %s" % total)</font></div><div><font face="monospace, monospace">```</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">vs</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">``` python</font></div><div><font face="monospace, monospace">import time</font></div><div><font face="monospace, monospace">from grass.pygrass.gis.region import Region</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">start = time.time()</font></div><div><font face="monospace, monospace">for i in range(10):</font></div><div><font face="monospace, monospace"> region = Region()</font></div><div><font face="monospace, monospace">end = time.time()</font></div><div><font face="monospace, monospace">total = end - start</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">print("Total time: %s" % total)</font></div><div><font face="monospace, monospace">```</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">## How much is the overhead exactly?</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">In order to measure the actual overhead of calling a GRASS module, I created two new</font></div><div><font face="monospace, monospace">GRASS modules that all they do is parse the command line arguments and measured how much</font></div><div><font face="monospace, monospace">time is needed for their execution. The first module is [`r.simple`]() and is</font></div><div><font face="monospace, monospace">implemented in Python while the other one is [`r.simple.c`]() and is implemented in C.</font></div><div><font face="monospace, monospace">The timings are in msec and the benchmark was executed using Python 3.7</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">| call method | r.simple | r.simple.c |</font></div><div><font face="monospace, monospace">|--------------------------------|:--------:|:----------:|</font></div><div><font face="monospace, monospace">| pygrass.module.Module | 85.9 | 66.5 |</font></div><div><font face="monospace, monospace">| pygrass.module.Module.shortcut | 85.5 | 66.9 |</font></div><div><font face="monospace, monospace">| grass.script.run_command | 41.3 | 30.5 |</font></div><div><font face="monospace, monospace">| subprocess.check_call | 41.8 | 30.3 |</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">As we can see, `gsrcipt.run_command` and `subprocess` give more or less a identical</font></div><div><font face="monospace, monospace">results, which is to be expected since `run_command` + friends are just a thin wrapper</font></div><div><font face="monospace, monospace">around `subprocess`. Similarly `shortcuts` has the same overhead as "vanila"</font></div><div><font face="monospace, monospace">`pygrass.Module`. Nevertheless, it is obvious that `pygrass` is roughly 2x times slower</font></div><div><font face="monospace, monospace">than `grass.script` (but more about that later).</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">As far as C vs Python goes, on my computer modules implemented in C seem to be 25% faster than their</font></div><div><font face="monospace, monospace">Python counterparts. Nevertheless, a 40 msec startup time doesn't seem extraordinary</font></div><div><font face="monospace, monospace">for a Python script, while 30 msec feels rather large for a CLI application implemented</font></div><div><font face="monospace, monospace">in C.</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">## Where is all that time being spent?</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">### C Modules</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">Unfortunately, I am not familiar enough with the GRASS internals to easily check what is</font></div><div><font face="monospace, monospace">going on and I didn't have the time to try to profile the code. I suspect that</font></div><div><font face="monospace, monospace">`G_gisinit` or something similar is causing the overhead, but someone more familiar with</font></div><div><font face="monospace, monospace">the C API should be able to enlighten us.</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">### Python Modules</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">In order to gain a better understanding of the overhead we have when calling python</font></div><div><font face="monospace, monospace">modules, we also need to measure the following quantities:</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">1. The time that python needs to spawn a new process</font></div><div><font face="monospace, monospace">2. The startup time for the python interpreter</font></div><div><font face="monospace, monospace">3. The time that python needs to `import grass`</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">These are the results:</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">| | msec |</font></div><div><font face="monospace, monospace">|-------------------------|:----:|</font></div><div><font face="monospace, monospace">| subprocess spawn | 1.2 |</font></div><div><font face="monospace, monospace">| python 2 startup | 9.0 |</font></div><div><font face="monospace, monospace">| python 2 + import grass | 24.5 |</font></div><div><font face="monospace, monospace">| python 3 startup | 18.2 |</font></div><div><font face="monospace, monospace">| python 3 + import grass | 39.3 |</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">As we can see:</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">- the overhead of spawning a new process from within python is more or less negligible</font></div><div><font face="monospace, monospace"> (at least compared to the other quantities).</font></div><div><font face="monospace, monospace">- The overhead of spawning a python 3 interpreter is 2x bigger than Python 2; i.e. the</font></div><div><font face="monospace, monospace"> transition to Python 3 will have some performance impact, no matter what.</font></div><div><font face="monospace, monospace">- The overhead of spawning a python 3 interpreter accounts for roughly 50% of the total</font></div><div><font face="monospace, monospace"> overhead (18 msec out of 41 msec).</font></div><div><font face="monospace, monospace">- The other 50% of the overhead is pretty much caused just by importing the `grass`</font></div><div><font face="monospace, monospace"> library.</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">## Why is Pygrass 2x times slower?</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">I haven't carefully looked into this (i.e. I haven't profiled the code), but it seems</font></div><div><font face="monospace, monospace">that the culprit is [this</font></div><div><font face="monospace, monospace">line](<a href="https://github.com/GRASS-GIS/grass-ci/blob/fe814a4fb73937ce96a36c11b6876db42acf28fa/lib/python/pygrass/modules/interface/module.py#L528" target="_blank">https://github.com/GRASS-GIS/grass-ci/blob/fe814a4fb73937ce96a36c11b6876db42acf28fa/lib/python/pygrass/modules/interface/module.py#L528</a>).</font></div><div><font face="monospace, monospace">In other words, `pygrass` calls a module twice, once to get the interface's description</font></div><div><font face="monospace, monospace">and once to actually run the module. That's why the overhead is double both for</font></div><div><font face="monospace, monospace">C modules and Python ones.</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">## Is this truly a problem?</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">Well, it depends :)</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">The most important factor is probably the size of the computational region. If you are</font></div><div><font face="monospace, monospace">dealing with really large regions, then the overhead is probably miniscule. If you are</font></div><div><font face="monospace, monospace">dealing with much smaller ones though, then it can be significant.</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">That being said, there are at least two cases where I think that this overhead is</font></div><div><font face="monospace, monospace">important:</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">- interactive sessions</font></div><div><font face="monospace, monospace">- running tests</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">Just to give an example, `i.pansharpen` calls ~50 other GRASS modules. On my laptop, the</font></div><div><font face="monospace, monospace">overhead for these calls is almost 2 seconds. Is this a lot? Well, if you are</font></div><div><font face="monospace, monospace">pansharpening Landsat Tiles, it probably is not that much, but you will have this</font></div><div><font face="monospace, monospace">overhead even if you are pansharpening a 4 pixel map (e.g. when running tests).</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">I am pretty sure that there are numerous other modules that are just like that, too.</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">## What is to be done?</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">I think that there are two different areas where work can be done:</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">1. Reduce the actual overhead; i.e. make calling GRASS modules faster.</font></div><div><font face="monospace, monospace">2. Convert calls to GRASS modules with API calls which, as shown earlier, are orders of</font></div><div><font face="monospace, monospace"> magnitude faster.</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">### Reduce the overhead</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">The overhead of Python and C modules has different causes.</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">As I said, I haven't looked into what causes C modules to take so long so i can't make</font></div><div><font face="monospace, monospace">any suggestions. This should be further looked into though. The reason is that modules</font></div><div><font face="monospace, monospace">like e.g. `g.region` are being used practically everywhere, so speeding these up should</font></div><div><font face="monospace, monospace">give a measureable performance improvement.</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">As far as Python modules go, unfortunately, the overhead seems to be relatively</font></div><div><font face="monospace, monospace">inelastic. Speeding up the startup time of the Python interpreter is not something that</font></div><div><font face="monospace, monospace">GRASS can do or rely upon. So, the only thing that can be actually be done is to try to</font></div><div><font face="monospace, monospace">reduce the time needed for importing the `grass` library. That being said, this should</font></div><div><font face="monospace, monospace">probably not skim more than a few ms at best, but at least the gains should be there for</font></div><div><font face="monospace, monospace">all python modules.</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">Luckily there is at least one relatively low hanging fruit. Speeding pygrass should not</font></div><div><font face="monospace, monospace">be that difficult. I haven't looked into this but pre-generating the modules' XML</font></div><div><font face="monospace, monospace">descriptions seems feasible and it should remove the need to call each module twice,</font></div><div><font face="monospace, monospace">thus making pygrass performance comparable to `grass.script.run_command`</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">### Convert module calls to API calls</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">Converting the module calls to API calls is what can potentially give the bigger</font></div><div><font face="monospace, monospace">benefits, but at the same time is what needs the most work.</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">There are some low hanging fruits here too. E.g. functions like `use_temp_region()` and</font></div><div><font face="monospace, monospace">`raster_info()` can probably be refactored to use the pygrass API, while calls to e.g.</font></div><div><font face="monospace, monospace">`g.region` can probably be replaced with `pygrass.gis.Region` objects etc.</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">Nevertheless, this does not really touch the root of the problem which IMHV is the tight</font></div><div><font face="monospace, monospace">coupling between the GRASS modules functionality and the CLI. In layman terms, at the</font></div><div><font face="monospace, monospace">moment, if you want to use module A from module B you are forced to spawn a new process</font></div><div><font face="monospace, monospace">and suffer the overhead that this entails.</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">TBH, I am not sure if this a problem that can even be tackled at this stage, but if each</font></div><div><font face="monospace, monospace">module had one or more functions that could be imported/called by other modules,</font></div><div><font face="monospace, monospace">everything would be much easier and performance would be significantly better.</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">## How to run the benchmark?</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">If you want to run this benchmark on your own you need to:</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">1. `git remote add panos <a href="https://github.com/pmav99/grass-ci.git" target="_blank">https://github.com/pmav99/grass-ci.git`</a></font></div><div><font face="monospace, monospace">1. `git fetch --all`</font></div><div><font face="monospace, monospace">1. `git checkout overhead`</font></div><div><font face="monospace, monospace">1. `cd scripts/r.simple && make && cd ../../`</font></div><div><font face="monospace, monospace">1. `cd raster/r.simple.c && make && cd ../../`</font></div><div><font face="monospace, monospace">1. Start a grass session</font></div><div><font face="monospace, monospace">1. `python benchmark.py`</font></div><div><font face="monospace, monospace"><br></font></div><div><font face="monospace, monospace">I haven't run the benchmark under Python 2, but even if there are incompatibilities,</font></div><div><font face="monospace, monospace">they should be trivial to fix.</font><br><br><font face="arial, helvetica, sans-serif">I will be happy to hear any remarks :)</font></div><div><font face="arial, helvetica, sans-serif"><br>with kind regards,</font></div><div><font face="arial, helvetica, sans-serif">Panos</font></div></div></div></div>
_______________________________________________<br>
grass-dev mailing list<br>
<a href="mailto:grass-dev@lists.osgeo.org" target="_blank">grass-dev@lists.osgeo.org</a><br>
<a href="https://lists.osgeo.org/mailman/listinfo/grass-dev" rel="noreferrer" target="_blank">https://lists.osgeo.org/mailman/listinfo/grass-dev</a></blockquote></div>
_______________________________________________<br>
grass-dev mailing list<br>
<a href="mailto:grass-dev@lists.osgeo.org" target="_blank">grass-dev@lists.osgeo.org</a><br>
<a href="https://lists.osgeo.org/mailman/listinfo/grass-dev" rel="noreferrer" target="_blank">https://lists.osgeo.org/mailman/listinfo/grass-dev</a></blockquote></div></div></div></div>