Improve performance of compiling routine with 1000 children.

[mstechly]

Describe the bug

While working on #190 I have changed a bit this test: test_compilation_works_as_expected_in_presence_of_large_number_of_children.
Now the timeout of 20 seconds actually sometimes fail (on 3.10 on CICD), so I increased it to 30 seconds and it passed.

However, the reason for this test was to catch performance regression, so we should do something about it.

Keep in mind that this is not just performance regression, as this test was previously working on preprocessing and now it's doing compilation, so now it has extra steps which might involve extra time. However, it would be good to actually investigate where does the difference in performance come from and fix the issue, as from perspective of the observable behaviour, it's just painfully slow.

I also decreased the number of children from 6000 to 1000.

Once we fix any performance issue that might be there, we should decrease the timeout again.

[bdg221]

@mstechly I have been doing testing on this issue and the results can be seen in a notebook on my fork.

Method of testing

I tested with Python 3.10.16 and 3.11.9 against Bartiq 0.10.0, 0.11.0, 0.12.0, the latest, and the latest with allow_transitive_resources=True. I used test_compilation_works_as_expected_in_presence_of_large_number_of_children in a separate file with N_CHILDREN=1000. The test with 6000 were taking over 15 minutes to run without allow_transitive_resources=True and roughly 30 seconds with the parameter set to True. A total of 5 tests were run for each scenario.

I gathered the performance results by running:
python -m cProfile -o performance_data/python3.10.16/0.12.0/perf_results_1.prof perf_test.py

Results in the notebook:

The mean and standard deviation were taken from the 5 tests for each scenario.

Without transitive resources, Sympy routinely took up roughly 75% of the execution time. Below are results from a single test run using Python 3.10.16 and the latest code with and without using transitive resources.

Latest Bartiq without using transitive resources
Total time spent running SymPy functions: 19.4954 seconds or 77.9768% of execution time
Total time spent running Bartiq functions: 0.2349 seconds or 0.9395% of execution time
SymPy Functions 19.495388
Bartiq Functions 0.234882
Other Functions 5.271259
dtype: float64

Latest Bartiq with using transitive resources
Total time spent running SymPy functions: 0.1871 seconds or 7.0518% of execution time
Total time spent running Bartiq functions: 0.2233 seconds or 8.4142% of execution time
SymPy Functions 0.187102
Bartiq Functions 0.223251
Other Functions 2.242900

SnakeViz results:

SnakeViz is very helpful for visualizing the runtime, especially in this case across Bartiq versions where parts of the compilation work moved to a different file/function.

Bartiq 0.11.0:

Bartiq 0.12.0+latest commit allow_transitive_resources=False:

Bartiq 0.12.0+latest commit allow_transitive_resources=True:

[mstechly]

This is a great analysis!
Thanks a lot @bdg221 , I think this basically closes the issue.
Just before I do it, one more question – I'm surprised to see that Python 3.11 was slower than 3.10 for this.
Any ideas why that might be the case?
Also CC: @dexter2206