Slow performance of project.find_records() for >1k records

[apdavison]

cf discussion on #308 and #309

[apdavison]

A quick profile of smt list for a project with 500 records, 3 output data files per record, gives:

$ python -m cProfile -o smt_list_profile_stats `which smt` list
$ ipython
In [1]: import pstats

In [2]: p = pstats.Stats('smt_list_profile_stats')

In [4]: p.sort_stats('time').print_stats(20)
Fri Dec  4 22:40:55 2015    smt_list_profile_stats

         10591974 function calls (10522012 primitive calls) in 9.296 seconds

   Ordered by: internal time
   List reduced from 5349 to 20 due to restriction <20>

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
     7025    0.356    0.000    0.499    0.000 /Users/andrew/anaconda/envs/sumatra/lib/python2.7/site-packages/django/db/backends/sqlite3/base.py:314(execute)
   327693    0.305    0.000    0.406    0.000 /Users/andrew/anaconda/envs/sumatra/lib/python2.7/site-packages/future/types/newstr.py:70(__new__)
   314628    0.205    0.000    0.556    0.000 /Users/andrew/anaconda/envs/sumatra/lib/python2.7/site-packages/future/types/newstr.py:112(__getitem__)
   369381    0.183    0.000    0.183    0.000 {hasattr}
   917090    0.169    0.000    0.289    0.000 /Users/andrew/anaconda/envs/sumatra/lib/python2.7/sre_compile.py:101(fixup)
    25064    0.142    0.000    0.244    0.000 /Users/andrew/anaconda/envs/sumatra/lib/python2.7/site-packages/django/db/models/base.py:388(__init__)
   849197    0.135    0.000    0.179    0.000 {isinstance}
      220    0.133    0.001    0.435    0.002 {map}
   254538    0.131    0.000    0.165    0.000 /Users/andrew/anaconda/envs/sumatra/lib/python2.7/site-packages/future/types/newstr.py:288(__eq__)
89305/69249    0.129    0.000    0.766    0.000 /Users/andrew/anaconda/envs/sumatra/lib/python2.7/site-packages/django/db/models/sql/compiler.py:352(compile)
282569/277402    0.126    0.000    0.129    0.000 {getattr}
    12024    0.122    0.000    0.982    0.000 /Users/andrew/anaconda/envs/sumatra/lib/python2.7/site-packages/future/types/newstr.py:120(__contains__)
   917620    0.119    0.000    0.119    0.000 {_sre.getlower}
     9032    0.115    0.000    0.117    0.000 {eval}
    12024    0.113    0.000    0.285    0.000 /Users/andrew/anaconda/envs/sumatra/lib/python2.7/site-packages/future/types/__init__.py:196(issubset)
    20066    0.108    0.000    0.355    0.000 /Users/andrew/anaconda/envs/sumatra/lib/python2.7/site-packages/django/db/models/sql/query.py:1339(names_to_path)
    13050    0.108    0.000    0.168    0.000 {method 'fetchmany' of 'sqlite3.Cursor' objects}
   123455    0.105    0.000    0.179    0.000 /Users/andrew/anaconda/envs/sumatra/lib/python2.7/site-packages/django/db/models/sql/compiler.py:335(quote_name_unless_alias)
    11041    0.101    0.000    0.187    0.000 /Users/andrew/anaconda/envs/sumatra/lib/python2.7/site-packages/django/db/models/sql/query.py:246(clone)
    28076    0.097    0.000    3.537    0.000 /Users/andrew/anaconda/envs/sumatra/lib/python2.7/site-packages/django/db/models/query.py:229(iterator)


Out[4]: <pstats.Stats instance at 0x105307320>

In [5]: p.sort_stats('cumulative').print_stats(20)
Fri Dec  4 22:40:55 2015    smt_list_profile_stats

         10591974 function calls (10522012 primitive calls) in 9.296 seconds

   Ordered by: cumulative time
   List reduced from 5349 to 20 due to restriction <20>

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000    9.320    9.320 /Users/andrew/anaconda/envs/sumatra/bin/smt:3(<module>)
        1    0.003    0.003    9.144    9.144 /Users/andrew/dev/sumatra/bin/smt:4(<module>)
        1    0.013    0.013    8.333    8.333 /Users/andrew/dev/sumatra/sumatra/commands.py:409(list)
        2    0.000    0.000    8.316    4.158 /Users/andrew/dev/sumatra/sumatra/projects.py:301(format_records)
        2    0.004    0.002    8.315    4.158 /Users/andrew/dev/sumatra/sumatra/projects.py:293(find_records)
        2    0.003    0.001    8.311    4.155 /Users/andrew/dev/sumatra/sumatra/recordstore/django_store/__init__.py:264(list)
     1002    0.078    0.000    7.464    0.007 /Users/andrew/dev/sumatra/sumatra/recordstore/django_store/models.py:274(to_sumatra)
     7021    0.037    0.000    3.576    0.001 /Users/andrew/anaconda/envs/sumatra/lib/python2.7/site-packages/django/db/models/query.py:963(_fetch_all)
    28076    0.097    0.000    3.537    0.000 /Users/andrew/anaconda/envs/sumatra/lib/python2.7/site-packages/django/db/models/query.py:229(iterator)
     5016    0.005    0.000    2.949    0.001 /Users/andrew/anaconda/envs/sumatra/lib/python2.7/site-packages/django/db/models/query.py:147(__iter__)
     7021    0.061    0.000    2.775    0.000 /Users/andrew/anaconda/envs/sumatra/lib/python2.7/site-packages/django/db/models/sql/compiler.py:813(execute_sql)
     9024    0.010    0.000    1.709    0.000 /Users/andrew/anaconda/envs/sumatra/lib/python2.7/site-packages/django/db/models/query.py:674(filter)
     9024    0.032    0.000    1.698    0.000 /Users/andrew/anaconda/envs/sumatra/lib/python2.7/site-packages/django/db/models/query.py:688(_filter_or_exclude)
     7021    0.082    0.000    1.584    0.000 /Users/andrew/anaconda/envs/sumatra/lib/python2.7/site-packages/django/db/models/sql/compiler.py:362(as_sql)
     9024    0.039    0.000    1.412    0.000 /Users/andrew/anaconda/envs/sumatra/lib/python2.7/site-packages/django/db/models/sql/query.py:1285(add_q)
     1002    0.003    0.000    1.363    0.001 /Users/andrew/dev/sumatra/sumatra/recordstore/django_store/models.py:150(to_sumatra)
     1002    0.018    0.000    1.360    0.001 /Users/andrew/dev/sumatra/sumatra/parameters.py:230(__init__)
     9024    0.052    0.000    1.340    0.000 /Users/andrew/anaconda/envs/sumatra/lib/python2.7/site-packages/django/db/models/sql/query.py:1311(_add_q)
     6012    0.035    0.000    1.178    0.000 /Users/andrew/dev/sumatra/sumatra/parameters.py:268(_parse_parameter_from_line)
     6012    0.014    0.000    1.160    0.000 /Users/andrew/anaconda/envs/sumatra/lib/python2.7/site-packages/django/db/models/manager.py:221(all)


Out[5]: <pstats.Stats instance at 0x105307320>