map del efficiency python2.2 and 2.1

[Jonathan Hogg]

On 16/7/2002 16:08, in article m28z4bn227.fsf at mother.paradise.lost, "John
Hunter" <jdhunter at nitace.bsd.uchicago.edu> wrote:

> In the process of profiling, however, I found something surprising.
> Most of the total execution time of the code is spent clearing the map
> from memory, after all the lines in my script have executed (ie, the
> equivalent of calling __del__ on a dictionary type.  In python 2.1,
> here is a typical execution time profile
> 
> time to read file as string and split into seq: 1.000s
> time to create map: 2.960s
> total execution time: 9.87s
> 
> 5.9s of the total runtime occurred *after* all the lines of my code
> had executed.  Since my program does nothing after reading the map, I
> assume most of this time is spent freeing the map.  If I comment out
> the part of my program that creates the map, I do not have that long
> delay at the end of the script.

I don't think you're reading these statistics correctly. Looking at the
output you include:

> #cruncher1:~/dict/test> time python2.1 test_allwords.py
> #seq has 1712676 items; elapsed time is 1.000
> #map has 856338 keys; time to load map is 2.960
> #4.400u 0.480s 0:09.87 49.4%    0+0k 0+0io 298pf+0w

The numbers along the bottom line (as returned by time) represent: the
user-space seconds spent on the CPU, the kernel-space seconds spent on the
CPU, the actual "wallclock" runtime of the process, and thus the percentage
of the runtime that it was actually on the CPU (as opposed to waiting for
I/O, VM, or pre-empted by some other process).

These numbers seem pretty consistent: 4.4 + 0.48 = 4.88 secs spent on the
CPU. You account for this as 1.000 secs for the load of the sequence and
2.960 secs on the map creation, which leaves only 0.920 secs spent
initialising and tearing down the Python interpreter.

> Finally, this time is dramatically longer in python 2.2.  Here are
> typical runtimes in 2.2

I think there is something bogus with your 2.2 install. Even reading the
numbers correctly they still leave 10 secs of CPU time unaccounted for and
you'd definitely notice the Python interpreter wasting that much time
starting and stopping.

Ignoring the numbers, how does the program actually seem to you? With the
runtime in the region of 10 to 27 seconds you should be able to gauge where
the time is going by just counting in your head as it runs. Does it look
like it's spending many seconds finishing up?

I modified your script to explicitly delete 's', 'seq', and 'm' and time
this. On my (twice as slow) machine it took 2/3rds of a CPU second to
deallocate all three.

Jonathan