Profiling simplification

[nkrusch]

• consider time as relative since it depends on # of cores
• not able to profile dense when it does not terminate (until I figure out how to add some timeout limit)
• for_body.c cannot be parsed and throws
• "before" == master branch, "after" === simpl branch

Some comparisons ordered by internal time:

---

infinite_8.c

before: 13224063 function calls (10707799 primitive calls) in 5.163 seconds

ncalls	tottime	percall	cumtime	percall	filename:lineno(function)
626833	0.623	0.000	0.927	0.000	polynomial.py:296(compare)
158893/1577	0.616	0.000	1.135	0.001	polynomial.py:352(sort_monomials)
6561	0.579	0.000	1.303	0.000	polynomial.py:237(eval)
1907969/448430	0.451	0.000	0.636	0.000	python3.7/json/encoder.py:277(_iterencode_list)
1607264	0.369	0.000	0.369	0.000	semiring.py:69(sum_mwp)
1597239	0.360	0.000	0.360	0.000	monomial.py:116(eval)

after: 2561855 function calls (2483457 primitive calls) in 1.328 seconds

ncalls	tottime	percall	cumtime	percall	filename:lineno(function)
284672	0.238	0.000	0.534	0.000	monomial.py:95(inclusion)
17709	0.206	0.000	0.760	0.000	polynomial.py:76(inclusion)
565173	0.193	0.000	0.193	0.000	monomial.py:79(contains)
334183	0.115	0.000	0.115	0.000	semiring.py:69(sum_mwp)
56065	0.057	0.000	0.083	0.000	polynomial.py:357(compare)
23335/1577	0.054	0.000	0.098	0.000	polynomial.py:413(sort_monomials)

---

notinfinite_8.c

before: 15474866 function calls (13029729 primitive calls) in 6.015 seconds

ncalls	tottime	percall	cumtime	percall	filename:lineno(function)
8451	1.409	0.000	3.085	0.000	polynomial.py:237(eval)
3659175	0.910	0.000	0.910	0.000	monomial.py:116(eval)
3662513	0.767	0.000	0.767	0.000	semiring.py:69(sum_mwp)
124347/1987	0.503	0.000	0.918	0.000	polynomial.py:352(sort_monomials)
1880855/440563	0.448	0.000	0.629	0.000	python3.7/json/encoder.py:277(_iterencode_list)
357668	0.357	0.000	0.534	0.000	polynomial.py:296(compare)

after: 2463339 function calls (2391520 primitive calls) in 1.308 seconds

ncalls	tottime	percall	cumtime	percall	filename:lineno(function)
290047	0.240	0.000	0.546	0.000	monomial.py:95(inclusion)
14298	0.210	0.000	0.777	0.000	polynomial.py:76(inclusion)
576027	0.201	0.000	0.201	0.000	monomial.py:79(contains)
363732	0.121	0.000	0.121	0.000	semiring.py:69(sum_mwp)
62967	0.064	0.000	0.094	0.000	polynomial.py:357(compare)
21887/1987	0.050	0.000	0.089	0.000	polynomial.py:413(sort_monomials)

---

To profile individual C file, the command is:

python -m cProfile -s tottime -m pymwp c_files/infinite_2.c

• replace -m pymwp to profile using old Analysis.py (though it pauses for user input so might not work?)
• replace c_files/infinite_2.c with whatever input you want to profile

[aubertc]

Neat, thanks.

Unless we have any reason to think that the examples we have are absolutely not representative, that seems to be a success.

For easier comparison:

infinite_8

/	function calls	primitive calls	time
before	13 224 063	10 707 799	5.163
after	2 561 855	2 483 457	1.328
"winner"	after	after	after

notinfinite_8.c

/	function calls	primitive calls	time
before	15 474 866	13 029 729	6.015
after	2 463 339	2 391 520	1.308
"winner"	after	after	after

[nkrusch]

This is a good improvement, first time I profiled these in Jan these same times were ~23s. I have also checked code quality and everything looks great there, well documented and good Python style.

Time for a PR?

[aubertc]

Youp. I'll let you take care of it. And close this issue?

[ThomasRuby]

Really nice ! Thanks @nkrusch !