[sqlalchemy] Re: loading tables is very slow

2008-08-28 Thread vkuznet

Hi,
so I modified a code to use hotshot module, basically I added

profiler = hotshot.Profile(profile.dat)
profiler.run(loadTables(tableNames))
profiler.close()

to my code instead of just calling loadTables function. Results are
below. I played with code a little bit and it seems to me that most of
the time spent in database/oracle.py, in reflecttable method of
OracleDialect class.

Anyway, let me know if more profile is necessary.
Thank you,
Valentin.


create engine 0.11220407486
engine.connect 1.89971590042
SELECT table_name FROM all_tables WHERE owner='ZZZ'
get tables 0.155882120132
Loading 'triggerpathdescription' table
5.56913805008
Load tables manually ['triggerpathdescription']
load table 5.57045388222
 1790 function calls (1717 primitive calls) in 5.570 CPU
seconds

   Ordered by: internal time, call count

   ncalls  tottime  percall  cumtime  percall
filename:lineno(function)
   252.9330.1172.9330.117 /opt/local/lib/python2.4/
site-packages/sqlalchemy/engine/base.py:1607(_fetchone_impl)
11.8091.8091.8091.809 /opt/local/lib/python2.4/
site-packages/sqlalchemy/engine/strategies.py:76(connect)
40.6620.1660.6620.166 /opt/local/lib/python2.4/
site-packages/sqlalchemy/engine/default.py:128(do_execute)
10.1460.1460.1470.147 /opt/local/lib/python2.4/
site-packages/sqlalchemy/pool.py:276(_finalize_fairy)
  2/10.0020.0013.6113.611 /opt/local/lib/python2.4/
site-packages/sqlalchemy/databases/oracle.py:439(reflecttable)
  147/1110.0010.0000.0020.000 /opt/local/lib/python2.4/
site-packages/sqlalchemy/engine/base.py:1590(_get_col)
   140.0010.0000.0020.000 /opt/local/lib/python2.4/
site-packages/sqlalchemy/schema.py:406(__init__)
   350.0010.0000.0010.000 /opt/local/lib/python2.4/
site-packages/sqlalchemy/sql/compiler.py:1001(_requires_quotes)
  1470.0010.0000.0010.000 /opt/local/lib/python2.4/
site-packages/sqlalchemy/util.py:121(__getitem__)
   380.0010.0000.0020.000 /opt/local/lib/python2.4/
site-packages/sqlalchemy/databases/oracle.py:366(_normalize_name)
40.0010.0000.0010.000 /opt/local/lib/python2.4/
site-packages/sqlalchemy/engine/base.py:1423(_init_metadata)
   250.0010.0002.9340.117 /opt/local/lib/python2.4/
site-packages/sqlalchemy/engine/base.py:1641(fetchone)
   140.0010.0000.0020.000 /opt/local/lib/python2.4/
site-packages/sqlalchemy/schema.py:583(_set_parent)
   900.0010.0000.0010.000 /opt/local/Library/
Frameworks/Python.framework/Versions/2.4/lib/python2.4/encodings/
utf_8.py:15(decode)
   410.0010.0000.0010.000 /opt/local/lib/python2.4/
site-packages/sqlalchemy/pool.py:442(__getattr__)
   160.0000.0000.0010.000 /opt/local/lib/python2.4/
site-packages/sqlalchemy/sql/expression.py:2651(__init__)
  1110.0000.0000.0030.000 /opt/local/lib/python2.4/
site-packages/sqlalchemy/engine/base.py:1338(__getitem__)
 10/10.0000.0000.0010.001 /opt/local/Library/
Frameworks/Python.framework/Versions/2.4/lib/python2.4/sre_parse.py:
374(_parse)
 11/10.0000.0000.0000.000 /opt/local/Library/
Frameworks/Python.framework/Versions/2.4/lib/python2.4/sre_compile.py:
27(_compile)
40.0000.0000.0000.000 /opt/local/lib/python2.4/
site-packages/sqlalchemy/pool.py:429(close)
   210.0000.0000.0000.000 /opt/local/lib/python2.4/
site-packages/sqlalchemy/engine/base.py:1299(__init__)
 11/10.0000.0000.0000.000 /opt/local/Library/
Frameworks/Python.framework/Versions/2.4/lib/python2.4/sre_parse.py:
140(getwidth)
40.0000.0000.0020.000 /opt/local/lib/python2.4/
site-packages/sqlalchemy/databases/oracle.py:216(get_result_proxy)
   720.0000.0000.0000.000 /opt/local/Library/
Frameworks/Python.framework/Versions/2.4/lib/python2.4/sre_parse.py:
182(__next)
   200.0000.0000.0000.000 /opt/local/lib/python2.4/
site-packages/sqlalchemy/util.py:472(__setitem__)
10.0000.0005.5705.570 test.py:14(loadTables)
  2/10.0000.0005.5675.567 /opt/local/lib/python2.4/
site-packages/sqlalchemy/engine/base.py:1267(reflecttable)
  2/10.0000.0005.5695.569 /opt/local/lib/python2.4/
site-packages/sqlalchemy/schema.py:124(__init__)
   200.0000.0000.0000.000 /opt/local/lib/python2.4/
site-packages/sqlalchemy/util.py:568(__setitem__)
   340.0000.0000.0000.000 /opt/local/lib/python2.4/
site-packages/sqlalchemy/sql/expression.py:1574(__contains__)
40.0000.0000.0010.000 /opt/local/lib/python2.4/
site-packages/sqlalchemy/engine/default.py:136(__init__)
50.0000.0000.0020.000 

[sqlalchemy] Re: loading tables is very slow

2008-08-28 Thread Michael Bayer

Below, you can see that establishing the database connection itself to  
oracle is taking 1.8 seconds (connect() on the SQLA side).  And a huge  
2.9 seconds to fetch just 25 rows from your Oracle database  
(_fetchone_impl on the SQLA side, which calls cursor.fetchone(), a  
cx_oracle native function, directly).   The total time spent waiting  
for results from cx_oracle, for a total of four statement executions  
(do_execute()), is .662 seconds.

So that is a total of 5.3 seconds spent entirely on the cx_oracle side  
of the equation, which is the time it's taking your oracle database to  
connect, execute four select statements, and fetch a total of 25  
rows.   0.2 seconds remain which is the time actually spent within  
SQLA's reflection implementation.

It seems you have an extremely slow network connection or an  
overloaded Oracle database.


On Aug 28, 2008, at 10:26 AM, vkuznet wrote:


 Hi,
 so I modified a code to use hotshot module, basically I added

 profiler = hotshot.Profile(profile.dat)
 profiler.run(loadTables(tableNames))
 profiler.close()

 to my code instead of just calling loadTables function. Results are
 below. I played with code a little bit and it seems to me that most of
 the time spent in database/oracle.py, in reflecttable method of
 OracleDialect class.

 Anyway, let me know if more profile is necessary.
 Thank you,
 Valentin.


 create engine 0.11220407486
 engine.connect 1.89971590042
 SELECT table_name FROM all_tables WHERE owner='ZZZ'
 get tables 0.155882120132
 Loading 'triggerpathdescription' table
 5.56913805008
 Load tables manually ['triggerpathdescription']
 load table 5.57045388222
 1790 function calls (1717 primitive calls) in 5.570 CPU
 seconds

   Ordered by: internal time, call count

   ncalls  tottime  percall  cumtime  percall
 filename:lineno(function)
   252.9330.1172.9330.117 /opt/local/lib/python2.4/
 site-packages/sqlalchemy/engine/base.py:1607(_fetchone_impl)
11.8091.8091.8091.809 /opt/local/lib/python2.4/
 site-packages/sqlalchemy/engine/strategies.py:76(connect)
40.6620.1660.6620.166 /opt/local/lib/python2.4/
 site-packages/sqlalchemy/engine/default.py:128(do_execute)
10.1460.1460.1470.147 /opt/local/lib/python2.4/
 site-packages/sqlalchemy/pool.py:276(_finalize_fairy)
  2/10.0020.0013.6113.611 /opt/local/lib/python2.4/
 site-packages/sqlalchemy/databases/oracle.py:439(reflecttable)
  147/1110.0010.0000.0020.000 /opt/local/lib/python2.4/
 site-packages/sqlalchemy/engine/base.py:1590(_get_col)
   140.0010.0000.0020.000 /opt/local/lib/python2.4/
 site-packages/sqlalchemy/schema.py:406(__init__)
   350.0010.0000.0010.000 /opt/local/lib/python2.4/
 site-packages/sqlalchemy/sql/compiler.py:1001(_requires_quotes)
  1470.0010.0000.0010.000 /opt/local/lib/python2.4/
 site-packages/sqlalchemy/util.py:121(__getitem__)
   380.0010.0000.0020.000 /opt/local/lib/python2.4/
 site-packages/sqlalchemy/databases/oracle.py:366(_normalize_name)
40.0010.0000.0010.000 /opt/local/lib/python2.4/
 site-packages/sqlalchemy/engine/base.py:1423(_init_metadata)
   250.0010.0002.9340.117 /opt/local/lib/python2.4/
 site-packages/sqlalchemy/engine/base.py:1641(fetchone)
   140.0010.0000.0020.000 /opt/local/lib/python2.4/
 site-packages/sqlalchemy/schema.py:583(_set_parent)
   900.0010.0000.0010.000 /opt/local/Library/
 Frameworks/Python.framework/Versions/2.4/lib/python2.4/encodings/
 utf_8.py:15(decode)
   410.0010.0000.0010.000 /opt/local/lib/python2.4/
 site-packages/sqlalchemy/pool.py:442(__getattr__)
   160.0000.0000.0010.000 /opt/local/lib/python2.4/
 site-packages/sqlalchemy/sql/expression.py:2651(__init__)
  1110.0000.0000.0030.000 /opt/local/lib/python2.4/
 site-packages/sqlalchemy/engine/base.py:1338(__getitem__)
 10/10.0000.0000.0010.001 /opt/local/Library/
 Frameworks/Python.framework/Versions/2.4/lib/python2.4/sre_parse.py:
 374(_parse)
 11/10.0000.0000.0000.000 /opt/local/Library/
 Frameworks/Python.framework/Versions/2.4/lib/python2.4/sre_compile.py:
 27(_compile)
40.0000.0000.0000.000 /opt/local/lib/python2.4/
 site-packages/sqlalchemy/pool.py:429(close)
   210.0000.0000.0000.000 /opt/local/lib/python2.4/
 site-packages/sqlalchemy/engine/base.py:1299(__init__)
 11/10.0000.0000.0000.000 /opt/local/Library/
 Frameworks/Python.framework/Versions/2.4/lib/python2.4/sre_parse.py:
 140(getwidth)
40.0000.0000.0020.000 /opt/local/lib/python2.4/
 site-packages/sqlalchemy/databases/oracle.py:216(get_result_proxy)
   720.0000.0000.0000.000 /opt/local/Library/