Re: [Modeling-users] ec.insert() timing

[Sebastien B. <sbi...@us...>]

Yannick Gingras <yan...@sa...> wrote:
> On September 11, 2003 07:08 am, you wrote:
> > Maybe sys.stderr is buffered, which may explain why you do not see the
> > "c\n" after insert, and why you do not notice any pause for
> > saveChanges() (which is very strange). Do you experience the same thing
> > with sys.stderr.flush() after write()?
>=20
> Unlike stdout, stderr should not but buffered but it's easy to try and
> most bugs lies in false assumptions:
[snip]
> Same result : \

  I do not understand what happens to you here. Could you try something
  like this:

     t_kvc=3D[]
     t_insert=3D[]
     t_save=3D[]
     for i in range(100):
         sys.stderr.write("%d\n" % i)
         newRec =3D self._dbClass()

         t=3Dtime()
         for key, value in self._defaults.items():
             newRec.takeValueForKey(value, key)
         t_kvc.append(time()-t)

         t=3Dtime()
         self._ec.insert(newRec)
         t_insert.append(time()-t)

         t=3Dtime()
         self._ec.saveChanges()
         t_save.append(time()-t)

    and report t_kvc, t_insert and t_save ?

> > Reassure me: when you say that <<The 100 record insert takes a few
> > minutes>>, that's under profiling, isn't it?
>=20
> Yes, the time I gave is under profiling:
>=20
>   >>> beg=3Dtime(); resp =3D insert(); end=3Dtime()
>   >>> print "%.2f s." % (end-beg)
>   230.03 s.
>=20
> But the non-profiled time is still a few minutes:
>=20
>   >>> beg=3Dtime(); resp =3D insert(); end=3Dtime()
>   >>> print "%.2f s." % (end-beg)
>   212.44 s.
>=20
> Without profiling, CPU usage stays under 20%, thats why I think about
> a lock synchronization problem.  I can't recall when this started
> because I usually insert an item at a time but I'm pretty sure that it
> have not alway been like this.  I'll try to downgrade my Modeling
> version and to load an old model with less entities.

  As I said, I do not understand. insertObject() does not lock anything
  on its own except the NotificationCenter (addObserver() is called in
  recordObject() called by insertObjectWithGlobalID() called by
  insertObject()), but I can't see any reason why it would hang there.

I'm not surprised that it takes such a long time *when profiling*, but
having about the same time when *not* profiling is astonishing --never
seen this before.

> Stay tuned !

        Ok!

-- S=E9bastien.