[Python-Dev] iterzip() (original) (raw)

Jeremy Hylton jeremy@zope.com
Mon, 29 Apr 2002 19:02:52 -0400

"NS" == Neil Schemenauer <nas@python.ca> writes:

How does this come into play in the benchmark in question? It seems like we should have gotten a lot of quick collections, but it was still quite slow.

NS> The GC cost is paid early and the objects get put in an older NS> generation. Obviously that's a waste of time if they are NS> deallocated in the near future. justpush deallocates as it goes NS> so the GC is never triggered.

The "0," tuples aren't deallocated until the end of the function, so it seems good to get them out of the current generation.

NS> I just tried measuring the time spent in the GC while loading NS> some nasty web pages in our system (stuff that looks at NS> thousands of objects). I used the Pentium cycle counter since NS> clock(2) seems to have very low resolution. Setting threshold0 NS> to 7500 makes the GC take up twice the amount of time as with NS> the default settings (700). That surprised me. I thought it NS> wouldn't make much difference. Maybe I screwed up. :-)

Here's some data from gprof to be puzzled by. I ran Tim's test with only run(storetups) enabled. Here's the top of the output:

Each sample counts as 0.01 seconds. % cumulative self self total
time seconds seconds calls ms/call ms/call name
60.19 0.62 0.62 112233 0.01 0.01 PyObject_Malloc 6.80 0.69 0.07 622804 0.00 0.00 visit_move 4.85 0.74 0.05 621301 0.00 0.00 visit_decref 4.85 0.79 0.05 168 0.30 0.67 list_traverse 3.88 0.83 0.04 145 0.28 0.41 move_roots 2.91 0.86 0.03 567141 0.00 0.00 tupletraverse 1.94 0.88 0.02 286727 0.00 0.00 gc_list_append 1.94 0.90 0.02 102050 0.00 0.00 tupledealloc 1.94 0.92 0.02 145 0.14 0.89 move_root_reachable 0.97 0.93 0.01 286727 0.00 0.00 gc_list_remove 0.97 0.94 0.01 113171 0.00 0.00 PyObject_Free 0.97 0.95 0.01 100043 0.00 0.00 list_ass_item 0.97 0.96 0.01 32702 0.00 0.00 PyDict_Next 0.97 0.97 0.01 489 0.02 1.78 eval_frame 0.97 0.98 0.01 280 0.04 0.04 instancemethod_dealloc 0.97 0.99 0.01 145 0.07 0.82 subtract_refs 0.97 1.00 0.01 145 0.07 0.07 update_refs 0.97 1.01 0.01 7 1.43 1.43 posix_stat 0.97 1.02 0.01 6 1.67 1.67 member_get 0.97 1.03 0.01 1 10.00 10.00 PyInt_Fini

So the profile output suggests that it's spending 60% of its time in pymalloc.

Jeremy