E
Eric S. Johansson
was profiling some of my code trying to figure out just why it was running slow and I discovered that shelves containing dictionaries were significantly slower than those containing simple tuples. for example, on a Pentium III/600 MHz machine the code below ran in 1.12 seconds but when I substituted a simple tuple for the shelf, it ran significantly faster (0.13 seconds). I'm confused as to why shelving dictionaries (all elements textual) should take so much longer is the pickel process that complex?.
----- test framework -----
#!/usr/bin/python
import sys
development_path = "/usr/local/camram/modules"
sys.path.insert(1,development_path)
import dbm_utils
import camram_utils
import configuration
#set the local context
config_data = configuration.configuration("esj")
def main():
# wrapper for shelf which also includes locking, file creation etc.
# returns object derived from type shelve.
spamtrap_cache = camram_utils.message_cache( configuration_data = config_data)
cnt =0
x = 0
# test code. Don't use without adding filename to message_cache
## while x<500:
## spamtrap_cache[str(x)]=(x,"const string")
## x=x+1
for i in spamtrap_cache.keys():
token = spamtrap_cache
cnt=cnt+1
print cnt
print token
import profile
profile.run('main()', '/tmp/speed')
import pstats
stats = pstats.Stats('/tmp/speed')
stats.strip_dirs().sort_stats('cumulative').print_stats()
stats.print_callees()
---- profile output
Tue Jun 22 14:25:48 2004 /tmp/speed
12479 function calls in 1.120 CPU seconds
Ordered by: cumulative time
ncalls tottime percall cumtime percall filename:lineno(function)
1 0.000 0.000 1.120 1.120 <string>:1(?)
1 0.000 0.000 1.120 1.120 profile:0(main())
1 0.030 0.030 1.120 1.120 speed.py:13(main)
566 0.960 0.002 1.080 0.002 shelve.py:69(__getitem__)
11887 0.120 0.000 0.120 0.000 <string>:0(?)
1 0.010 0.010 0.010 0.010 shelve.py:55(keys)
2 0.000 0.000 0.000 0.000 posixpath.py:362(normpath)
0 0.000 0.000 profile:0(profiler)
1 0.000 0.000 0.000 0.000 shelve.py:82(close)
1 0.000 0.000 0.000 0.000 whichdb.py:5(whichdb)
1 0.000 0.000 0.000 0.000 anydbm.py:69(open)
2 0.000 0.000 0.000 0.000 configuration.py:294(__getitem__)
2 0.000 0.000 0.000 0.000 configuration.py:355(path_process)
1 0.000 0.000 0.000 0.000 dbm_utils.py:53(bias_anydbm)
1 0.000 0.000 0.000 0.000 shelve.py:52(__init__)
1 0.000 0.000 0.000 0.000 dbm_utils.py:359(__init__)
2 0.000 0.000 0.000 0.000 configuration.py:80(base_pathname)
2 0.000 0.000 0.000 0.000 posixpath.py:299(expanduser)
1 0.000 0.000 0.000 0.000 portalocker.py:68(lock)
1 0.000 0.000 0.000 0.000 shelve.py:89(__del__)
1 0.000 0.000 0.000 0.000 camram_utils.py:329(close)
2 0.000 0.000 0.000 0.000 posixpath.py:330(expandvars)
1 0.000 0.000 0.000 0.000 camram_utils.py:314(__init__)
Ordered by: cumulative time
Function called...
<string>:1(?) shelve.py:89(__del__)(1) 0.000
speed.py:13(main)(1) 1.120
profile:0(main()) <string>:1(?)(1) 1.120
speed.py:13(main) camram_utils.py:314(__init__)(1) 0.000
shelve.py:55(keys)(1) 0.010
shelve.py:69(__getitem__)(566) 1.080
shelve.py:69(__getitem__) <string>:0(?)(11887) 0.120
<string>:0(?) --
shelve.py:55(keys) --
posixpath.py:362(normpath) --
profile:0(profiler) profile:0(main())(1) 1.120
shelve.py:82(close) --
whichdb.py:5(whichdb) --
anydbm.py:69(open) whichdb.py:5(whichdb)(1) 0.000
configuration.py:294(__getitem__) configuration.py:355(path_process)(2) 0.000
configuration.py:355(path_process) configuration.py:80(base_pathname)(2) 0.000
dbm_utils.py:53(bias_anydbm) --
shelve.py:52(__init__) --
dbm_utils.py:359(__init__) anydbm.py:69(open)(1) 0.000
dbm_utils.py:53(bias_anydbm)(1) 0.000
shelve.py:52(__init__)(1) 0.000
configuration.py:80(base_pathname) posixpath.py:299(expanduser)(2) 0.000
posixpath.py:330(expandvars)(2) 0.000
posixpath.py:362(normpath)(2) 0.000
posixpath.py:299(expanduser) --
portalocker.py:68(lock) --
shelve.py:89(__del__) camram_utils.py:329(close)(1) 0.000
camram_utils.py:329(close) shelve.py:82(close)(1) 0.000
posixpath.py:330(expandvars) --
camram_utils.py:314(__init__) configuration.py:294(__getitem__)(2) 0.000
dbm_utils.py:359(__init__)(1) 0.000
portalocker.py:68(lock)(1) 0.000
----- test framework -----
#!/usr/bin/python
import sys
development_path = "/usr/local/camram/modules"
sys.path.insert(1,development_path)
import dbm_utils
import camram_utils
import configuration
#set the local context
config_data = configuration.configuration("esj")
def main():
# wrapper for shelf which also includes locking, file creation etc.
# returns object derived from type shelve.
spamtrap_cache = camram_utils.message_cache( configuration_data = config_data)
cnt =0
x = 0
# test code. Don't use without adding filename to message_cache
## while x<500:
## spamtrap_cache[str(x)]=(x,"const string")
## x=x+1
for i in spamtrap_cache.keys():
token = spamtrap_cache
cnt=cnt+1
print cnt
print token
import profile
profile.run('main()', '/tmp/speed')
import pstats
stats = pstats.Stats('/tmp/speed')
stats.strip_dirs().sort_stats('cumulative').print_stats()
stats.print_callees()
---- profile output
Tue Jun 22 14:25:48 2004 /tmp/speed
12479 function calls in 1.120 CPU seconds
Ordered by: cumulative time
ncalls tottime percall cumtime percall filename:lineno(function)
1 0.000 0.000 1.120 1.120 <string>:1(?)
1 0.000 0.000 1.120 1.120 profile:0(main())
1 0.030 0.030 1.120 1.120 speed.py:13(main)
566 0.960 0.002 1.080 0.002 shelve.py:69(__getitem__)
11887 0.120 0.000 0.120 0.000 <string>:0(?)
1 0.010 0.010 0.010 0.010 shelve.py:55(keys)
2 0.000 0.000 0.000 0.000 posixpath.py:362(normpath)
0 0.000 0.000 profile:0(profiler)
1 0.000 0.000 0.000 0.000 shelve.py:82(close)
1 0.000 0.000 0.000 0.000 whichdb.py:5(whichdb)
1 0.000 0.000 0.000 0.000 anydbm.py:69(open)
2 0.000 0.000 0.000 0.000 configuration.py:294(__getitem__)
2 0.000 0.000 0.000 0.000 configuration.py:355(path_process)
1 0.000 0.000 0.000 0.000 dbm_utils.py:53(bias_anydbm)
1 0.000 0.000 0.000 0.000 shelve.py:52(__init__)
1 0.000 0.000 0.000 0.000 dbm_utils.py:359(__init__)
2 0.000 0.000 0.000 0.000 configuration.py:80(base_pathname)
2 0.000 0.000 0.000 0.000 posixpath.py:299(expanduser)
1 0.000 0.000 0.000 0.000 portalocker.py:68(lock)
1 0.000 0.000 0.000 0.000 shelve.py:89(__del__)
1 0.000 0.000 0.000 0.000 camram_utils.py:329(close)
2 0.000 0.000 0.000 0.000 posixpath.py:330(expandvars)
1 0.000 0.000 0.000 0.000 camram_utils.py:314(__init__)
Ordered by: cumulative time
Function called...
<string>:1(?) shelve.py:89(__del__)(1) 0.000
speed.py:13(main)(1) 1.120
profile:0(main()) <string>:1(?)(1) 1.120
speed.py:13(main) camram_utils.py:314(__init__)(1) 0.000
shelve.py:55(keys)(1) 0.010
shelve.py:69(__getitem__)(566) 1.080
shelve.py:69(__getitem__) <string>:0(?)(11887) 0.120
<string>:0(?) --
shelve.py:55(keys) --
posixpath.py:362(normpath) --
profile:0(profiler) profile:0(main())(1) 1.120
shelve.py:82(close) --
whichdb.py:5(whichdb) --
anydbm.py:69(open) whichdb.py:5(whichdb)(1) 0.000
configuration.py:294(__getitem__) configuration.py:355(path_process)(2) 0.000
configuration.py:355(path_process) configuration.py:80(base_pathname)(2) 0.000
dbm_utils.py:53(bias_anydbm) --
shelve.py:52(__init__) --
dbm_utils.py:359(__init__) anydbm.py:69(open)(1) 0.000
dbm_utils.py:53(bias_anydbm)(1) 0.000
shelve.py:52(__init__)(1) 0.000
configuration.py:80(base_pathname) posixpath.py:299(expanduser)(2) 0.000
posixpath.py:330(expandvars)(2) 0.000
posixpath.py:362(normpath)(2) 0.000
posixpath.py:299(expanduser) --
portalocker.py:68(lock) --
shelve.py:89(__del__) camram_utils.py:329(close)(1) 0.000
camram_utils.py:329(close) shelve.py:82(close)(1) 0.000
posixpath.py:330(expandvars) --
camram_utils.py:314(__init__) configuration.py:294(__getitem__)(2) 0.000
dbm_utils.py:359(__init__)(1) 0.000
portalocker.py:68(lock)(1) 0.000