Profiling Golly Scripts
Posted: December 17th, 2015, 8:16 pm
Now that I learned how to profile Golly scripts instead of timing manually, I would like to share it here. Fortunately, Golly's profiling module cProfile works fine.
As you all know, launching a Golly script blocks stdout, so you have to print anything via g.show() which is quite inconvenient. Profiling is no exception, and just running cProfile.run(function()) would do nothing as it prints the information to stdout.
Here's my attempt on profiling A for Awesome's brand new hack on apgsearch:
Basically, I wrapped all the global code to main() and ran cProfile. There were two caveats when I was working with the code:
1) A for Awesome's version of apgsearch used a global variable 'ruletype', so I had to use cProfile.runctx instead of cProfile.run. Also, for an unknown reason, just def main(): (which makes main access to the global variable) doesn't work. I had to tweak the code to def main(ruletype=ruletype): to make it work.
2) If Golly had allowed stdout, then life would have been much easier. A single cProfile.run(ctx) would have displayed the information nicely. It doesn't, so I had to dump the profile results to an external file 'apgprofile_dump' and (sort and) display it with pstats.
Any questions are welcome, but I suggest you first reading the profiler section of the Python docs and google it first.
EDIT: And here's how it looks like! apgprofile.txt (I only ran 200 soups cause it's soooo slow in my computer...)
As you all know, launching a Golly script blocks stdout, so you have to print anything via g.show() which is quite inconvenient. Profiling is no exception, and just running cProfile.run(function()) would do nothing as it prints the information to stdout.
Here's my attempt on profiling A for Awesome's brand new hack on apgsearch:
Code: Select all
...Same as A for Awesome's verson...
def main(ruletype=ruletype):
# Obtain the parameters to conduct the search:
number = int(g.getstring("How many soups to search?", "5000000"))
....A lot of code....
soup.display_unids()
soup.display_census(scount, rootstring, symm, symmstring)
PROFILE = True
if PROFILE:
import cProfile
import pstats
cProfile.runctx('main()', globals(), locals(), filename='apgprofile_dump')
with open('apgprofile.txt', 'w') as profileresults:
st = pstats.Stats('apgprofile_dump', stream=profileresults)
st.sort_stats('tottime')
st.print_stats()
else:
main()1) A for Awesome's version of apgsearch used a global variable 'ruletype', so I had to use cProfile.runctx instead of cProfile.run. Also, for an unknown reason, just def main(): (which makes main access to the global variable) doesn't work. I had to tweak the code to def main(ruletype=ruletype): to make it work.
2) If Golly had allowed stdout, then life would have been much easier. A single cProfile.run(ctx) would have displayed the information nicely. It doesn't, so I had to dump the profile results to an external file 'apgprofile_dump' and (sort and) display it with pstats.
Any questions are welcome, but I suggest you first reading the profiler section of the Python docs and google it first.
EDIT: And here's how it looks like! apgprofile.txt (I only ran 200 soups cause it's soooo slow in my computer...)
Code: Select all
Fri Dec 18 09:01:24 2015 apgprofile_dump
353559 function calls in 29.203 seconds
Ordered by: internal time
ncalls tottime percall cumtime percall filename:lineno(function)
393 9.912 0.025 9.912 0.025 {golly.new}
4 5.148 1.287 5.148 1.287 {golly.getstring}
14684 2.906 0.000 2.906 0.000 {golly.run}
128550 1.812 0.000 1.812 0.000 {golly.getcell}
487 1.809 0.004 1.809 0.004 {golly.setrule}
698 1.112 0.002 2.409 0.003 /home/scorbie/Apps/golly/Scripts/Perl/apgsearch-2015-12-17-v0.54+0.1i.py:10932(gridobj)
294 0.997 0.003 1.502 0.005 /home/scorbie/Apps/golly/Scripts/Perl/apgsearch-2015-12-17-v0.54+0.1i.py:49(hashsoup)
3232 0.861 0.000 1.793 0.001 /home/scorbie/Apps/golly/Scripts/Perl/apgsearch-2015-12-17-v0.54+0.1i.py:238(canonise_orientation)
89 0.674 0.008 0.674 0.008 {golly.step}
105894 0.620 0.000 0.620 0.000 {method 'append' of 'list' objects}
626 0.436 0.001 0.436 0.001 {golly.getcells}
16405 0.362 0.000 0.362 0.000 {golly.getpop}
137 0.272 0.002 2.291 0.017 /home/scorbie/Apps/golly/Scripts/Perl/apgsearch-2015-12-17-v0.54+0.1i.py:11042(naivestab)
200 0.179 0.001 0.931 0.005 /home/scorbie/Apps/golly/Scripts/Perl/apgsearch-2015-12-17-v0.54+0.1i.py:11061(naivestab2)
4178 0.147 0.000 0.147 0.000 {golly.hash}
6029 0.143 0.000 0.143 0.000 {golly.setcell}
3580 0.131 0.000 0.131 0.000 {golly.getrect}
200 0.125 0.001 0.125 0.001 {golly.clear}
17062 0.125 0.000 0.125 0.000 {max}
94 0.118 0.001 0.118 0.001 {golly.store}
394 0.099 0.000 0.099 0.000 {golly.setalgo}
2 0.099 0.050 18.637 9.319 /home/scorbie/Apps/golly/Scripts/Perl/apgsearch-2015-12-17-v0.54+0.1i.py:11274(teenager)
3232 0.096 0.000 0.163 0.000 /home/scorbie/Apps/golly/Scripts/Perl/apgsearch-2015-12-17-v0.54+0.1i.py:273(compare_representations)
12962 0.096 0.000 0.096 0.000 {min}
15501 0.095 0.000 0.095 0.000 {len}
390 0.080 0.000 2.065 0.005 /home/scorbie/Apps/golly/Scripts/Perl/apgsearch-2015-12-17-v0.54+0.1i.py:209(canonise)
23 0.077 0.003 0.077 0.003 {golly.fit}
1 0.074 0.074 0.074 0.074 {golly.open}
790 0.071 0.000 0.071 0.000 {golly.putcells}
370 0.071 0.000 11.923 0.032 /home/scorbie/Apps/golly/Scripts/Perl/apgsearch-2015-12-17-v0.54+0.1i.py:11442(process_unid)
390 0.064 0.000 0.423 0.001 /home/scorbie/Apps/golly/Scripts/Perl/apgsearch-2015-12-17-v0.54+0.1i.py:11168(bijoscar)
9429 0.054 0.000 0.054 0.000 {ord}
106 0.049 0.000 0.049 0.000 {golly.getdir}
2 0.045 0.022 23.227 11.613 /home/scorbie/Apps/golly/Scripts/Perl/apgsearch-2015-12-17-v0.54+0.1i.py:11364(stabilise_soups_parallel)
20 0.030 0.001 0.069 0.003 /home/scorbie/Apps/golly/Scripts/Perl/apgsearch-2015-12-17-v0.54+0.1i.py:10895(grabobj)
67 0.023 0.000 0.023 0.000 {golly.setbase}
709 0.021 0.000 0.030 0.000 /home/scorbie/Apps/golly/Scripts/Perl/apgsearch-2015-12-17-v0.54+0.1i.py:10795(awardpoints2)
370 0.020 0.000 2.232 0.006 /home/scorbie/Apps/golly/Scripts/Perl/apgsearch-2015-12-17-v0.54+0.1i.py:11215(enter_unid)
8 0.018 0.002 0.018 0.002 {golly.show}
136 0.011 0.000 0.012 0.000 /home/scorbie/Apps/golly/Scripts/Perl/apgsearch-2015-12-17-v0.54+0.1i.py:683(newvar)
400 0.011 0.000 0.011 0.000 {golly.select}
1480 0.011 0.000 0.011 0.000 {method 'pop' of 'list' objects}
94 0.010 0.000 0.618 0.007 /home/scorbie/Apps/golly/Scripts/Perl/apgsearch-2015-12-17-v0.54+0.1i.py:11629(save_soup)
17 0.009 0.001 1.111 0.065 /home/scorbie/Apps/golly/Scripts/Perl/apgsearch-2015-12-17-v0.54+0.1i.py:464(pseudo_bangbang)
1 0.008 0.008 0.008 0.008 /home/scorbie/Apps/golly/Scripts/Perl/apgsearch-2015-12-17-v0.54+0.1i.py:614(setrule)
719 0.008 0.000 0.008 0.000 /home/scorbie/Apps/golly/Scripts/Perl/apgsearch-2015-12-17-v0.54+0.1i.py:10779(incobject)
388 0.008 0.000 0.008 0.000 {_hashlib.openssl_sha256}
200 0.006 0.000 3.228 0.016 /home/scorbie/Apps/golly/Scripts/Perl/apgsearch-2015-12-17-v0.54+0.1i.py:11090(stabilise3)
1 0.006 0.006 0.700 0.700 /home/scorbie/Apps/golly/Scripts/Perl/apgsearch-2015-12-17-v0.54+0.1i.py:11649(display_census)
412 0.006 0.000 0.006 0.000 {time.clock}
709 0.004 0.000 0.004 0.000 /home/scorbie/Apps/golly/Scripts/Perl/apgsearch-2015-12-17-v0.54+0.1i.py:10787(awardpoints)
294 0.004 0.000 0.004 0.000 {method 'digest' of '_hashlib.HASH' objects}
19 0.004 0.000 0.004 0.000 {golly.join}
40 0.004 0.000 0.006 0.000 /home/scorbie/Apps/golly/Scripts/Perl/apgsearch-2015-12-17-v0.54+0.1i.py:706(scoline)
390 0.003 0.000 0.003 0.000 {abs}
23 0.003 0.000 0.003 0.000 {golly.update}
320 0.002 0.000 0.002 0.000 {chr}
15 0.002 0.000 0.014 0.001 /home/scorbie/Apps/golly/Scripts/Perl/apgsearch-2015-12-17-v0.54+0.1i.py:695(newvars)
2 0.002 0.001 1.473 0.736 /home/scorbie/Apps/golly/Scripts/Perl/apgsearch-2015-12-17-v0.54+0.1i.py:10826(census)
30 0.002 0.000 0.002 0.000 {posix.stat}
95 0.002 0.000 0.002 0.000 {method 'hexdigest' of '_hashlib.HASH' objects}
1 0.001 0.001 0.012 0.012 /home/scorbie/Apps/golly/Scripts/Perl/apgsearch-2015-12-17-v0.54+0.1i.py:11550(save_progress)
69 0.001 0.000 0.001 0.000 {golly.setstep}
1 0.001 0.001 29.203 29.203 /home/scorbie/Apps/golly/Scripts/Perl/apgsearch-2015-12-17-v0.54+0.1i.py:11795(main)
1 0.001 0.001 0.006 0.006 /home/scorbie/Apps/golly/Scripts/Perl/apgsearch-2015-12-17-v0.54+0.1i.py:1517(saveContagiousLife)
30 0.001 0.000 0.002 0.000 /usr/lib/python2.7/genericpath.py:15(exists)
10 0.001 0.000 0.047 0.005 /home/scorbie/Apps/golly/Scripts/Perl/apgsearch-2015-12-17-v0.54+0.1i.py:658(saverule)
1 0.001 0.001 0.056 0.056 /home/scorbie/Apps/golly/Scripts/Perl/apgsearch-2015-12-17-v0.54+0.1i.py:1165(saveClassifyObjects)
3 0.000 0.000 0.000 0.000 {open}
3 0.000 0.000 0.000 0.000 {method 'close' of 'file' objects}
4 0.000 0.000 0.000 0.000 {sorted}
3 0.000 0.000 0.000 0.000 {method 'write' of 'file' objects}
1 0.000 0.000 0.003 0.003 /home/scorbie/Apps/golly/Scripts/Perl/apgsearch-2015-12-17-v0.54+0.1i.py:1054(saveCoalesceObjects)
1 0.000 0.000 0.068 0.068 /home/scorbie/Apps/golly/Scripts/Perl/apgsearch-2015-12-17-v0.54+0.1i.py:600(saveAllRules)
1 0.000 0.000 0.031 0.031 /home/scorbie/Apps/golly/Scripts/Perl/apgsearch-2015-12-17-v0.54+0.1i.py:11528(display_unids)
8 0.000 0.000 0.000 0.000 {range}
6 0.000 0.000 0.000 0.000 /home/scorbie/Apps/golly/Scripts/Perl/apgsearch-2015-12-17-v0.54+0.1i.py:11780(ord2)
1 0.000 0.000 0.000 0.000 {built-in method now}
2 0.000 0.000 0.000 0.000 {golly.getevent}
1 0.000 0.000 0.000 0.000 /home/scorbie/Apps/golly/Scripts/Perl/apgsearch-2015-12-17-v0.54+0.1i.py:135(check)
1 0.000 0.000 0.002 0.002 /home/scorbie/Apps/golly/Scripts/Perl/apgsearch-2015-12-17-v0.54+0.1i.py:987(saveExpungeObjects)
1 0.000 0.000 0.001 0.001 /home/scorbie/Apps/golly/Scripts/Perl/apgsearch-2015-12-17-v0.54+0.1i.py:1459(savePropagateClassifications)
4 0.000 0.000 0.000 0.000 {method 'iteritems' of 'dict' objects}
4 0.000 0.000 0.000 0.000 {method 'copy' of 'dict' objects}
1 0.000 0.000 29.203 29.203 <string>:1(<module>)
1 0.000 0.000 0.000 0.000 {_hashlib.openssl_md5}
2 0.000 0.000 0.000 0.000 {method 'startswith' of 'str' objects}
1 0.000 0.000 0.000 0.000 /home/scorbie/Apps/golly/Scripts/Perl/apgsearch-2015-12-17-v0.54+0.1i.py:907(saveEradicateInfection)
1 0.000 0.000 0.000 0.000 {method 'isoformat' of 'datetime.datetime' objects}
1 0.000 0.000 0.000 0.000 /home/scorbie/Apps/golly/Scripts/Perl/apgsearch-2015-12-17-v0.54+0.1i.py:782(saveExpungeGliders)
2 0.000 0.000 0.000 0.000 {method 'split' of 'str' objects}
1 0.000 0.000 0.000 0.000 /home/scorbie/Apps/golly/Scripts/Perl/apgsearch-2015-12-17-v0.54+0.1i.py:945(savePercolateInfection)
1 0.000 0.000 0.000 0.000 /home/scorbie/Apps/golly/Scripts/Perl/apgsearch-2015-12-17-v0.54+0.1i.py:827(saveIdentifyGliders)
1 0.000 0.000 0.000 0.000 /home/scorbie/Apps/golly/Scripts/Perl/apgsearch-2015-12-17-v0.54+0.1i.py:722(saveHandlePlumes)
1 0.000 0.000 0.000 0.000 {math.sqrt}
1 0.000 0.000 0.000 0.000 /home/scorbie/Apps/golly/Scripts/Perl/apgsearch-2015-12-17-v0.54+0.1i.py:158(convert)
1 0.000 0.000 0.000 0.000 {method 'disable' of '_lsprof.Profiler' objects}