[Zope-DB] DCOracle2 cursor.execute is getting incredible slow

[Willi Langenberger]

Hi Matt, Chris and all!


I'm using DCOracle2-1.3b with Oracle-8.1.7.

I found that under certain circumstances, the DCOracle2 cursor.execute
call gets slower and slower (to incredible slow).

What I did (schematically):

  keys = get_all_primary_keys_from_table()  # returns a few 1000 keys

  dbc = DCOracle2.connect(...)
  cursor = dbc.cursor()
  for n, key in enumerate(keys):
    t1 = time.time()
    cursor.execute("select * from SAMPLE_TABLE where key = :1", key)
    t2 = time.time()
    logfile.write("%d %f\n" % (n, t2-t1))
    row = cursor.fetchone()   # primary keys return exactly one row

If I use gnuplot to display the logged data, i get the following graph:

  http://slime.wu-wien.ac.at/misc/pa0000.png

The execution time starts with about 1ms and ends with 30ms (30 times
slower).

I tried to track down the time sink and found following path:

DCOracle2.py:cursor.execute
  dco2:Cursor_execute
    dco2:Cursor_getdesc
      OCIParamGet

Each time Cursor_execute is called, this calls Cursor_getdesc, which
in turn calls OCIParamGet. And OCIParamGet gets slower on each call.

And now ...... my questions:

  * Any ideas what causes OCIParamGet to get slower?

  * Is it really necessary to call Cursor_getdesc for each
    Cursor_execute call? The description for the cursor shouldn't
    change, as long as there is no new Cursor_prepare call, isnt it?


Any help is very much appreciated!


\wlang{}

PS: 2 more observation:

- if the table has many colums, the slope is higher. The following table
  has 288 columns (and doubles the execution time after 150 executes):

    http://slime.wu-wien.ac.at/misc/pa0008.png

- closing and reopening the cursor after every 100 executes helps:

    http://slime.wu-wien.ac.at/misc/pa0008-reopen.png


-- 
Willi.Langenberger at wu-wien.ac.at                Fax: +43/1/31336/9207
Zentrum fuer Informatikdienste, Wirtschaftsuniversitaet Wien, Austria