[Modeling-users] RE: Lazy Initialization Part 2

SourceForge Headquarters 225 Broadway Suite 1600 San Diego, CA 92101 +1 (858) 422-6466

=2D----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

On July 11, 2003 01:32 am, you wrote:
>   A quick note about this: I wrote it a bit too quickly yesterday.  Even
> w/ to-one rel., you'll still have to pay for the extra round-trip to the
>
> db when accessing the inverse to-many rel:
> >>> ec=3DEditingContext()
> >>> objs=3Dec.fetch('Book') # fetch all books
> >>> gids=3D[o.globalID() for o in objs]
> >>> pks=3D[gid.keyValues()['id'] for gid in gids]
> >>> objs[0].getAuthor().isFault()
> >>> 1
> >>> ec.fetch('Writer', 'books.id in %s'%pks) # all fetches at once
> >>> objs[0].getAuthor().isFault() # no round-trip to the db
> >>> 0
> >>> objs[0].getAuthor().getBooks() # additional round-trip to the db
>
>   ...for the very same reason I explained in the previous post. I'm
>   thinking of a way to avoid this, but will probably no have the time
>   until tuesday to test and code it.
>
>   In the meantime, as I said, I'm quite interesting in hearing from the
>   performance you observe w/ your db when prefetching the rels. and
>   setting MDL_PERMANENT_DB_CONNECTION to 1.

Iterative fetch of the i18ns array wo/ MDL_PERMANENT_DB_CONNECTION :

        User time (seconds): 15.18
        System time (seconds): 0.70
        Percent of CPU this job got: 79%
        Elapsed (wall clock) time (h:mm:ss or m:ss): 0:19.89

Iterative fetch of the i18ns array w/ MDL_PERMANENT_DB_CONNECTION :

        User time (seconds): 14.29
        System time (seconds): 0.33
        Percent of CPU this job got: 83%
        Elapsed (wall clock) time (h:mm:ss or m:ss): 0:17.49

2 fetch, one for masters, one with "IN" for i18ns :

        User time (seconds): 13.99
        System time (seconds): 0.17
        Percent of CPU this job got: 87%
        Elapsed (wall clock) time (h:mm:ss or m:ss): 0:16.17

 : \

The very same query typed at the prompt with a SQL JOIN spit an
amazing amount of data in my face before it print "1440 rows in set
(0.02 sec)"...  I understand that I have to pay a price for the abstraction=
=20
provided by the framework but... well, it's it's beyond usability here... :=
 (

The I have detailed profiler logs :=20

Thu Jul 10 17:21:24 2003    /tmp/@25817.0

         1557967 function calls (1008710 primitive calls) in 39.780 CPU=20
seconds

   Ordered by: internal time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
546199/5876   15.900    0.000   15.900    0.003=20
/usr/lib/python2.2/site-packages/Modeling/QualifierParser.py:112(__str__)
    39164    1.310    0.000    1.870    0.000=20
/usr/lib/python2.2/threading.py:99(release)
    39164    1.160    0.000    1.870    0.000=20
/usr/lib/python2.2/threading.py:81(acquire)
     2173    1.040    0.000    6.790    0.003=20
/usr/lib/python2.2/site-packages/Modeling/DatabaseContext.py:1228(initializ=
eObject)
     2176    0.770    0.000   17.470    0.008=20
/usr/lib/python2.2/site-packages/Modeling/DatabaseChannel.py:110(fetchObjec=
t)
    78328    0.680    0.000    0.680    0.000=20
/usr/lib/python2.2/threading.py:44(_note)
     4362    0.660    0.000    1.160    0.000=20
/usr/lib/python2.2/site-packages/Modeling/Model.py:119(entityNamed)
    78328    0.590    0.000    0.590    0.000=20
/usr/lib/python2.2/threading.py:581(currentThread)
    72588    0.530    0.000    0.530    0.000=20
/usr/lib/python2.2/site-packages/Modeling/Entity.py:565(name)
     2924    0.510    0.000    0.650    0.000=20
/home/ygingras/modules/spark.py:209(buildState)
     2173    0.510    0.000    1.010    0.000=20
/usr/lib/python2.2/site-packages/NotificationFramework/NotificationCenter.p=
y:249(addObserver)
    12271    0.510    0.000    0.770    0.000=20
/usr/lib/python2.2/site-packages/Modeling/KeyValueCoding.py:149(takeStoredV=
alueForKey)
    10868    0.470    0.000    1.560    0.000=20
/usr/lib/python2.2/site-packages/Modeling/ClassDescription.py:76(classDescr=
iptionForName)
    24542    0.450    0.000    0.630    0.000=20
/usr/lib/python2.2/site-packages/Modeling/utils.py:50(capitalizeFirstLetter)
    12271    0.440    0.000    0.810    0.000=20
/usr/lib/python2.2/site-packages/Modeling/KeyValueCoding.py:130(storedValue=
=46orKey)
    15216    0.400    0.000    1.110    0.000=20
/usr/lib/python2.2/site-packages/Modeling/Database.py:381(lock)
     2173    0.350    0.000    2.480    0.001=20
/usr/lib/python2.2/site-packages/Modeling/CustomObject.py:233(snapshot)
     2176    0.350    0.000    0.800    0.000=20
/usr/lib/python2.2/site-packages/Modeling/DatabaseAdaptors/AbstractDBAPI2Ad=
aptorLayer/AbstractDBAPI2AdaptorChannel.py:175(fetchRow)
     4346    0.340    0.000    0.560    0.000=20
/usr/lib/python2.2/site-packages/Modeling/Entity.py:348(classProperties_att=
ributes)
     2173    0.330    0.000    0.390    0.000=20
/usr/lib/python2.2/site-packages/Modeling/EntityClassDescription.py:452(cla=
ssForEntity)
    17384    0.330    0.000    0.710    0.000=20
/usr/lib/python2.2/site-packages/Modeling/CustomObject.py:121(classDescript=
ion)
     2173    0.320    0.000    1.130    0.001=20
/usr/lib/python2.2/site-packages/Modeling/EditingContext.py:182(addObjectFo=
rGlobalID)
     2173    0.310    0.000    0.410    0.000=20
/usr/lib/python2.2/site-packages/Modeling/EntityClassDescription.py:122(att=
ributesKeys)
    39114    0.280    0.000    0.280    0.000=20
/usr/lib/python2.2/site-packages/Modeling/GlobalID.py:185(__hash__)
   2935/3    0.280    0.000   15.930    5.310=20
/home/ygingras/modules/spark.py:330(buildTree_r)
    51287    0.270    0.000    0.270    0.000=20
/usr/lib/python2.2/site-packages/Modeling/Attribute.py:261(name)
    36828    0.250    0.000    0.250    0.000=20
/usr/lib/python2.2/site-packages/Modeling/Attribute.py:234(isClassProperty)
    12271    0.250    0.000    0.280    0.000=20
/usr/lib/python2.2/site-packages/Modeling/Entity.py:346(<lambda>)
     4346    0.240    0.000    0.240    0.000=20
/usr/lib/python2.2/site-packages/Modeling/GlobalID.py:176(__str__)
        3    0.240    0.080    0.410    0.137=20
/home/ygingras/modules/spark.py:66(tokenize)
    12271    0.220    0.000    0.220    0.000=20
/usr/lib/python2.2/site-packages/Modeling/DatabaseObject.py:174(attributeNa=
meForKey)
     2173    0.210    0.000    9.060    0.004=20
/usr/lib/python2.2/site-packages/Modeling/ObjectStoreCoordinator.py:371(ini=
tializeObject)
[...]

A lot of time is spent parsing the qualifier and building the SQL
query.  Could spark be an unexpected bottle neck ?  The "IN" query
does not seems to scale really well for large value lists.

Is there any hope or should I forget about the nice abstraction provided by=
=20
Modeling and craft my own SQL ?

=2D --=20
Yannick Gingras
Byte Gardener, Savoir-faire Linux inc.
(514) 276-5468

=2D----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.2.1 (GNU/Linux)

iD8DBQE/DxCdrhy5Fqn/MRARAs4ZAJ9L+DASFZ2lNjt+rIcm81gbIH4JUgCfba0d
3ZS00rZII0AcXTbzee/IpLo=3D
=3D6I8u
=2D----END PGP SIGNATURE-----