time after time

well, I've run this test a few times and I consistently get the same result. 
running a single CRM 114 is no faster than running numeral for concurrent CRM 
114 processes.  not only that, I still get the same distorted scores results.

I've run this test on virtual and physical machines and get approximately the 
same results.  I'm going to run the tests on a physical machine again tonight 
and publish them separately.

the first set of data is the number of training events that occur in a given 
time.  For example, 0.5 seconds had two training events take that long.  Sorry, 
I didn't sort it.  Also, rule out the 0.0 line.  I think there's a bug in my 
statistics gathering there.  The second check again it is the result of the 
command run through time.  As you can see, it's relatively evenly split between 
user and system time.

A single run:


0.0, 10378
0.5, 2
0.1, 690
0.2, 34
1.0, 1
0.3, 1
0.6, 1

real    25m56.214s
user    11m25.260s
sys     13m36.850s

now, let's look at 4 processes running at the same time.  Now in order to give 
CRM 11 for the best possible advantage, all four processes are using the same 
.css files.  in theory, the CSS image would be mapped into memory and generally 
stay there as long as there was a least one process using it.  Uh-huh.

0.0, 9236
0.5, 31
0.2, 480
0.8, 7
0.1, 3
0.6, 58
0.3, 1007
0.4, 221
0.9, 1
0.7, 63


real    94m46.274s
user    11m25.460s
sys     11m56.510s

0.0, 9263
0.5, 27
0.4, 209
0.2, 471
0.1, 4
0.6, 36
0.3, 1016
0.8, 20
0.9, 3
0.7, 58

real    94m44.155s
user    11m23.110s
sys     11m58.610s

0.0, 9253
0.5, 41
0.8, 15
0.4, 200
1.0, 3
0.1, 4
0.6, 50
0.3, 1017
0.2, 470
0.7, 54

real    94m45.234s
user    11m22.620s
sys     12m0.060s

0.0, 9264
0.5, 28
0.8, 14
0.2, 432
1.0, 1
0.1, 7
0.6, 42
0.3, 1036
0.4, 220
0.9, 1
1.7, 1
0.7, 61

real    94m43.708s
user    11m20.050s
sys     12m0.210s

they all take roughly 4 times the execution time of a single process.  The load 
average climbed to about three plus.  You can see why I've come to the 
conclusion that a single threaded CRM 114 is just as efficient as multiples 
running at the same time.

needs some refinement but is is clear that forking is taking a *big* chunk of time.

also separately I collected some stats on performance of my Python code just in 
case I was doing something "unpleasant".  this is one of those moments where I 
wish Thunderbird would not wrap lines.

 >>> stats.print_stats()
Tue Jun  3 10:52:55 2008    /tmp/crm114.perf

          1871173 function calls in 63.730 CPU seconds

    Ordered by: cumulative time, internal time

    ncalls  tottime  percall  cumtime  percall filename:lineno(function)
         1    0.000    0.000   63.730   63.730 test_train.py:149(main)
         1    0.000    0.000   63.730   63.730 profile:0(main())
         1    0.000    0.000   63.730   63.730 <string>:1(<module>)
         1   11.150   11.150   63.720   63.720 test_train.py:45(retrain)
     11107    1.760    0.000   34.450    0.003 
/home/esj/projects/crm114-test/crm114.py:187(score_message)
     11591    2.070    0.000   23.690    0.002 
/usr/lib/python2.5/subprocess.py:535(__init__)
     11591    0.910    0.000   20.440    0.002 
/usr/lib/python2.5/subprocess.py:1037(_execute_child)
     11591   14.870    0.001   14.870    0.001 :0(fork)
     11591    0.170    0.000   10.590    0.001 
/usr/lib/python2.5/subprocess.py:643(communicate)
     11591    1.950    0.000   10.420    0.001 
/usr/lib/python2.5/subprocess.py:1183(_communicate)
      8059    1.410    0.000    8.320    0.001 
/home/esj/projects/crm114-test/crm114.py:157(train_as_bad)
      8059    1.380    0.000    6.140    0.001 
/home/esj/projects/crm114-test/crm114.py:33(dump_stack)
      8059    0.200    0.000    4.520    0.001 
/usr/lib/python2.5/traceback.py:131(format_exception)
     77126    3.750    0.000    3.750    0.000 :0(read)
      3048    0.290    0.000    3.110    0.001 
/home/esj/projects/crm114-test/crm114.py:126(train_as_good)
      8059    0.000    0.000    3.100    0.000 
/usr/lib/python2.5/traceback.py:74(format_tb)
     48160    0.030    0.000    2.490    0.000 
/usr/lib/python2.5/subprocess.py:981(_read_no_intr)
     44428    2.440    0.000    2.440    0.000 :0(time)
     39306    2.330    0.000    2.330    0.000 :0(isinstance)
       484    0.140    0.000    2.310    0.005 
/home/esj/projects/crm114-test/crm114.py:80(CRM114_train)
     92729    2.260    0.000    2.260    0.000 :0(close)
     11591    1.670    0.000    2.090    0.000 
/usr/lib/python2.5/subprocess.py:1174(wait)
     43459    1.950    0.000    1.960    0.000 
/usr/lib/python2.5/posixpath.py:56(join)
      8059    0.910    0.000    1.780    0.000 
/usr/lib/python2.5/traceback.py:78(extract_tb)
    135679    1.700    0.000    1.700    0.000 :0(select)
     43343    1.410    0.000    1.410    0.000 :0(syslog)
      8059    1.310    0.000    1.320    0.000 
/usr/lib/python2.5/traceback.py:27(format_list)
      8059    0.500    0.000    1.220    0.000 
/usr/lib/python2.5/traceback.py:148(format_exception_only)
     34773    1.140    0.000    1.140    0.000 :0(fdopen)
     11591    0.050    0.000    1.030    0.000 
/usr/lib/python2.5/subprocess.py:961(_set_cloexec_flag)
     23182    0.980    0.000    0.980    0.000 :0(fcntl)
     87485    0.870    0.000    0.870    0.000 :0(append)
     99110    0.170    0.000    0.760    0.000 
/usr/lib/python2.5/subprocess.py:993(_write_no_intr)
     99110    0.590    0.000    0.590    0.000 :0(write)

-------------------------------------------------------------------------
Check out the new SourceForge.net Marketplace.
It's the best place to buy or sell services for
just about anything Open Source.
http://sourceforge.net/services/buy/index.php