Re: [sqlite] Strange execution times

[Ulrich Schöbel]

Hi John,

there isn't really much to remove, but nevertheless I
followed your advice and replaced the sqlite select
by a small standard tcl procedure. Maybe that set me
on the right track.

There were also some exceptionally high execution
times in between, but not in every test run and not
always at the same repetition count. Those peaks
had a slight tendency to occur at 500, 1000 and
5000 repetitions. From time to time they occured at
other counts or not at all.

I have a couple of daemons running on the machine,
doing several things at more or less arbitrary moments.
I suspect them to be the reason for this behaviour.

One thing still boggles me: The peaks in my timing
experiments with sqlite are reproducibly at a constant
repetition count with approximately predictible times,
as opposed the 'statistical' peaks in the sqlite-less
case.

Unless someone comes up with a similar timing description,
I herewith declare this 'dilemma' solved.

Thank you all for your help and sorry for the alarm.

Kind regards

Ulrich

On Wednesday 22 February 2006 23:41, John Stanton wrote:
> Ulrich, try designing an experiment which removes SQLITE and measures
> the performance of the other software layers.  That might resolve your
> dilemma.
> JS
>

Re: [sqlite] Strange execution times

[John Stanton]

Ulrich, try designing an experiment which removes SQLITE and measures 
the performance of the other software layers.  That might resolve your 
dilemma.

JS

Ulrich Schöbel wrote:

Hi Richard,

thanks for trying to reproduce my 'problem'.

I'm using Linux 2.6.12 (Ubuntu Breezy Badger, a debian distro),
Tcl/Tk 8.4.12, sqlite 3.3.4, all pretty recent versions.

I made the same tests today with the same results.

Nevertheless, sqlite is by far faster than mySQL, so I'm going
to switch to it, anyway. But I'm still curious, where this effect
is coming from.

Thanks

Ulrich


On Wednesday 22 February 2006 14:27, [EMAIL PROTECTED] wrote:


Ulrich =?iso-8859-1?q?Sch=F6bel?= <[EMAIL PROTECTED]> wrote:


% time {db eval {select * from cust_persons where first_name='Ulrich'}}
1000 75.498 microseconds per iteration
% time {db eval {select * from cust_persons where first_name='Ulrich'}}
1 51.6179 microseconds per iteration
% time {db eval {select * from cust_persons where first_name='Ulrich'}}
100 309.95 microseconds per iteration
% time {db eval {select * from cust_persons where first_name='Ulrich'}}
10 66.8 microseconds per iteration

Where do those 309.95 microseconds come from? What's the
difference between running a query 100 times or 1 times?
Should I avoid running a select exactly 100 times for some
obscure reason?


FWIW, I am unable to reproduce your problem)  I get
a smooth transition from 10 iterations (84 uS/iteration) to
1 (58 uS/iteration).

What OS are you using?  And what version of Tcl/Tk?
--
D. Richard Hipp   <[EMAIL PROTECTED]>

Re: [sqlite] Strange execution times

[Dennis Jenkins]

Ulrich Schöbel wrote:
> Hi Richard,
>
> thanks for trying to reproduce my 'problem'.
>
> I'm using Linux 2.6.12 (Ubuntu Breezy Badger, a debian distro),
> Tcl/Tk 8.4.12, sqlite 3.3.4, all pretty recent versions.
>
> I made the same tests today with the same results.
>
> Nevertheless, sqlite is by far faster than mySQL, so I'm going
> to switch to it, anyway. But I'm still curious, where this effect
> is coming from.
>
>   

Could you (or someone) write the test in 'C' and compile it with
"-ggprof" flag on gcc and run it in the profiler?

I propose that the test program should take one command line argument,
the # of iterations.  That way you can profile "1" vs "50" vs "10"
independently of each other.

Re: [sqlite] Strange execution times

[Jose Da Silva]

On February 22, 2006 05:59 am, Adrian Ho wrote:
> On Wed, Feb 22, 2006 at 11:11:45AM +0200, Ulrich Sch?bel wrote:
> > I tried your script and got, after a slight modification, quite
> > consistent results. When I tried it as is, I got slightly varying
> > time results with a peak in the 50 to 100 region. Then I
> > commented out all lines concerning the deletion, creation
> > and filling to get the pure retrieval times. Drom then on
> > I got the following almost invariable results,

You probably need to consider time-slices because you are working with a 
multitasking operating system in which you have 1 CPU doing a little of 
each task so that you get multiple processes done at the same time.

For example an old OS/2 warp3 running on a 40MHz 386 would slice a 
second into 32 partitions and allocate processes into each of those 
partitions. In that case, you would get timing with granularity of 1/32 
of a second and might fit 4 queries in one slice and 1 query in the 
next available slice. You also need to take into account background 
tasks such as reading/writing harddrive, etc. which also skew your 
results, therefore if you want an idea of timing, you really should 
deal with large sets of runs.
Even the old versions of windows timer functions were only reliable down 
to about 100ms slices or something like that.
Later versions of operating systems expect to run on fast processors and 
would be waiting forever with nothing to do with only 32 multitasking 
slices per second, and therefore divide 1 second into far more slices, 
maybe 100 or 1000 slices per second, which also translates into more 
consistent results from your point of view. Tasks such as disk I/O are 
an eternity of waiting for something like a 1GHz computer.

For example, this may have started on 1 time slice but had to wait for 
disk i/o to complete it's task in another time slice... who knows, 
maybe even the disk I/O caches needed to get flushed to work on the new 
file???:

> > t(1)=538 microseconds per iteration

This may have managed to complete all 5 tasks in 1 time slice, and may 
already have been loaded into the disk I/O cache buffers???:

> > t(5)=69.2 microseconds per iteration

This may have been lucky to squeeze all 10 tasks in 1 time slice:

> > t(10)=39.9 microseconds per iteration

No comment here because the large runs below are more consistent.
> > t(50)=391.48 microseconds per iteration
> > t(100)=215.61 microseconds per iteration
> > t(500)=73.154 microseconds per iteration

These number are more consistent because you sort of skip the problem of 
time slicing, disk buffers and flushing, because you deal with large 
runs of info. These are the types of numbers you run to get a good idea 
of timing:

> > t(1000)=54.753 microseconds per iteration
> > t(5000)=40.9094 microseconds per iteration
> > t(1)=39.4558 microseconds per iteration

Hope that helps from an Operating System point of view.

Re: [sqlite] sqlite, odbc, any gotchas?

[Jay Sprenkle]

On 2/21/06, Jose Da Silva <[EMAIL PROTECTED]> wrote:
> On February 21, 2006 12:48 pm, Jay Sprenkle wrote:
> > Sqlite has been very fast for me. If you need raw blazing
>
> Well, sqlite is definitely fast in relation to other sqls, but every sql
> has overhead, and they all can't match direct access of a
> flattish-file-format by a computer doing it's own work of accessing the
> files directly (assuming smallish small-company files at this point,
> versus large user-base files).
>
> > speed Access and ODBC are not the way to go.
>
> True, but still have to deal with convincing and converting users who
> get fed their information via slick-glossy magazines, so at this point,
> there is still the stigma to overcome and the user-base needs to be
> introduced to alternatives slowly.

LOL! I have certainly seen that!  That and the FUD people spread about
and some people manufacture on their own!

> The odbc allows my options to remain open as to how to implement the
> webstuff, and possibly other alternatives of access. The alternative
> was accessing DBF files directly from the server, therfore allowing me
> to also read DBF files via linux and eventually the webserver stuff.
>
> Your suggestion about database corruption is a definite drop of DBF and
> committing with odbc.  Thanks

Good luck!

Re: [sqlite] what if sqlite_finalize() fails?

[drh]

Michael Knigge <[EMAIL PROTECTED]> wrote:
> > THe bigger question is why you are designing a new system to
> > work with SQLite-2.  SQLite-2 is in maintenance for use on legacy
> 
> Eh... sorry, I was in a hurry of course I use sqlite3_finalize()!
> 
> 
> > systems.  Use SQLite-3 instead.  sqlite3_finalize() cannot fail
> > for any reason other than SQLITE_MISUSE.
> 
> Then have a look at
> 
> http://www.sqlite.org/capi3ref.html#sqlite3_finalize
> 
> 
> All prepared statements must finalized before sqlite3_close() is called 
> or else the close will fail with a return code of SQLITE_BUSY.
> .
> Incomplete updates may be rolled back and transactions canceled, 
> depending on the circumstances, and the result code returned will be 
> SQLITE_ABORT.
> 
> 

If sqlite3_finalize() returns SQLITE_ABORT, it merely means that
you finalized an operation that was in process.  The statement
still gets finalized.
--
D. Richard Hipp   <[EMAIL PROTECTED]>

Re: [sqlite] what if sqlite_finalize() fails?

[Michael Knigge]

THe bigger question is why you are designing a new system to
work with SQLite-2.  SQLite-2 is in maintenance for use on legacy


Eh... sorry, I was in a hurry of course I use sqlite3_finalize()!



systems.  Use SQLite-3 instead.  sqlite3_finalize() cannot fail
for any reason other than SQLITE_MISUSE.


Then have a look at

http://www.sqlite.org/capi3ref.html#sqlite3_finalize


All prepared statements must finalized before sqlite3_close() is called 
or else the close will fail with a return code of SQLITE_BUSY.


Incomplete updates may be rolled back and transactions canceled, 
depending on the circumstances, and the result code returned will be 
SQLITE_ABORT.




Bye,
  Michael

Re: [sqlite] Strange execution times

[Ulrich Schöbel]

On Wednesday 22 February 2006 15:59, Adrian Ho wrote:

> > Do you come to similar results?
>
> Nope, mine were a lot more consistent (Centrino 1.6GHz laptop, 512MB RAM):
>
> t(1)=254 microseconds per iteration
> t(5)=186.6 microseconds per iteration
> t(10)=156.1 microseconds per iteration
> t(50)=147.24 microseconds per iteration
> t(100)=144.88 microseconds per iteration
> t(500)=153.658 microseconds per iteration
> t(1000)=142.218 microseconds per iteration
> t(5000)=142.7774 microseconds per iteration
> t(1)=143.1704 microseconds per iteration

As were Richards. Looks like an issue of my machine/installation,
but I'm perfectly clueless.

> > I have to oppose your statement, Tcl has garbage collection.
> > It doesn't, at least in the sense, that it calls a routine to
> > collect unused space and free it at arbitrary times, i.e. during
> > idle times.
>
> Ah, that's where our perspectives differ.  The definition of "garbage
> collection" which I'm operating from (which I believe is the classical
> CS one) makes no reference whatsoever to time, other than the implicit
> "at some point after it's been identified as garbage".

OK, almost no difference except for the definition.

> While that's true, I'd point out that unset'ing a large list/array,
> or otherwise destroying a heavily-referenced Tcl_Obj, can cause a huge
> cascade of derefs/deletes, so it's not necessarily the case that Tcl's
> GC times are always predictably similar even across iterations of the
> same script.

Right, but my test script is way too simple for such effects.

> I'm keeping an open mind on this one, since I have no hard data to back
> up any conclusion whatsoever.  And since you've subsequently indicated
> that it's now a non-issue (esp. in comparison to MySQL), I guess I'll
> shut up now.  8-)

Thanks for your support. If you have an idea on this later on,
please let me know. I'm staying tuned.

Kind regards

Ulrich

Re: [sqlite] Strange execution times

[Adrian Ho]

On Wed, Feb 22, 2006 at 11:11:45AM +0200, Ulrich Sch?bel wrote:
> I tried your script and got, after a slight modification, quite
> consistent results. When I tried it as is, I got slightly varying
> time results with a peak in the 50 to 100 region. Then I
> commented out all lines concerning the deletion, creation
> and filling to get the pure retrieval times. Drom then on
> I got the following almost invariable results,
> 
> t(1)=538 microseconds per iteration
> t(5)=69.2 microseconds per iteration
> t(10)=39.9 microseconds per iteration
> t(50)=391.48 microseconds per iteration
> t(100)=215.61 microseconds per iteration
> t(500)=73.154 microseconds per iteration
> t(1000)=54.753 microseconds per iteration
> t(5000)=40.9094 microseconds per iteration
> t(1)=39.4558 microseconds per iteration
> 
> The t(1) time is probably due to Tcls bytecode engine, but
> the t(50) and t(100) times are inexplicable, at least for me.
> 
> The 'mini database' you use is, apart from a few additional
> fields, almost identical to the one I used in my previous tests.
> 
> Do you come to similar results?

Nope, mine were a lot more consistent (Centrino 1.6GHz laptop, 512MB RAM):

t(1)=254 microseconds per iteration
t(5)=186.6 microseconds per iteration
t(10)=156.1 microseconds per iteration
t(50)=147.24 microseconds per iteration
t(100)=144.88 microseconds per iteration
t(500)=153.658 microseconds per iteration
t(1000)=142.218 microseconds per iteration
t(5000)=142.7774 microseconds per iteration
t(1)=143.1704 microseconds per iteration

> I have to oppose your statement, Tcl has garbage collection.
> It doesn't, at least in the sense, that it calls a routine to
> collect unused space and free it at arbitrary times, i.e. during
> idle times.

Ah, that's where our perspectives differ.  The definition of "garbage
collection" which I'm operating from (which I believe is the classical
CS one) makes no reference whatsoever to time, other than the implicit
"at some point after it's been identified as garbage".

> Tcl collects its garbage when there is some. Tcls objects are reference
> counted and as soon as this count reaches zero the object is cleaned
> up. This costs time, of course, but it happens each time the garbage
> is due. That has the effect, that garbage collection times are simply
> included in execution times, regularly.

While that's true, I'd point out that unset'ing a large list/array,
or otherwise destroying a heavily-referenced Tcl_Obj, can cause a huge
cascade of derefs/deletes, so it's not necessarily the case that Tcl's
GC times are always predictably similar even across iterations of the
same script.

In any case, this is the SQlite list rather than the tcl-core list, so
returning to the subject at hand...

> It should not produce the peak times I see at t(50) and t(100).

I'm keeping an open mind on this one, since I have no hard data to back
up any conclusion whatsoever.  And since you've subsequently indicated
that it's now a non-issue (esp. in comparison to MySQL), I guess I'll
shut up now.  8-)

- Adrian

Re: [sqlite] Strange execution times

[Ulrich Schöbel]

Hi Richard,

thanks for trying to reproduce my 'problem'.

I'm using Linux 2.6.12 (Ubuntu Breezy Badger, a debian distro),
Tcl/Tk 8.4.12, sqlite 3.3.4, all pretty recent versions.

I made the same tests today with the same results.

Nevertheless, sqlite is by far faster than mySQL, so I'm going
to switch to it, anyway. But I'm still curious, where this effect
is coming from.

Thanks

Ulrich


On Wednesday 22 February 2006 14:27, [EMAIL PROTECTED] wrote:
> Ulrich =?iso-8859-1?q?Sch=F6bel?= <[EMAIL PROTECTED]> wrote:
> > % time {db eval {select * from cust_persons where first_name='Ulrich'}}
> > 1000 75.498 microseconds per iteration
> > % time {db eval {select * from cust_persons where first_name='Ulrich'}}
> > 1 51.6179 microseconds per iteration
> > % time {db eval {select * from cust_persons where first_name='Ulrich'}}
> > 100 309.95 microseconds per iteration
> > % time {db eval {select * from cust_persons where first_name='Ulrich'}}
> > 10 66.8 microseconds per iteration
> >
> > Where do those 309.95 microseconds come from? What's the
> > difference between running a query 100 times or 1 times?
> > Should I avoid running a select exactly 100 times for some
> > obscure reason?
>
> FWIW, I am unable to reproduce your problem)  I get
> a smooth transition from 10 iterations (84 uS/iteration) to
> 1 (58 uS/iteration).
>
> What OS are you using?  And what version of Tcl/Tk?
> --
> D. Richard Hipp   <[EMAIL PROTECTED]>

Re: [sqlite] what if sqlite_finalize() fails?

[drh]

Michael Knigge <[EMAIL PROTECTED]> wrote:
> All,
> 
> I wonder what I have to do if sqlite_finalize() fails? sqlite_close() 
> will fail if there are any prepared statements associated with a 
> database handle - so I can't close.
> 
> Due to the manual, sqlite_finalize() could return SQLITE_ABORT - do I 
> have to call sqlite_finalize() again in this case?
> 

THe bigger question is why you are designing a new system to
work with SQLite-2.  SQLite-2 is in maintenance for use on legacy
systems.  Use SQLite-3 instead.  sqlite3_finalize() cannot fail
for any reason other than SQLITE_MISUSE.
--
D. Richard Hipp   <[EMAIL PROTECTED]>

Re: [sqlite] Strange execution times

[drh]

Ulrich =?iso-8859-1?q?Sch=F6bel?= <[EMAIL PROTECTED]> wrote:
> 
> % time {db eval {select * from cust_persons where first_name='Ulrich'}} 1000
> 75.498 microseconds per iteration
> % time {db eval {select * from cust_persons where first_name='Ulrich'}} 1
> 51.6179 microseconds per iteration
> % time {db eval {select * from cust_persons where first_name='Ulrich'}} 100
> 309.95 microseconds per iteration
> % time {db eval {select * from cust_persons where first_name='Ulrich'}} 10
> 66.8 microseconds per iteration
> 
> Where do those 309.95 microseconds come from? What's the
> difference between running a query 100 times or 1 times?
> Should I avoid running a select exactly 100 times for some
> obscure reason?
> 

FWIW, I am unable to reproduce your problem)  I get
a smooth transition from 10 iterations (84 uS/iteration) to
1 (58 uS/iteration).  

What OS are you using?  And what version of Tcl/Tk?
--
D. Richard Hipp   <[EMAIL PROTECTED]>

[sqlite] Comparison (see: Strange execution times)

[Ulrich Schöbel]

Hi all,

out of curiosity I made the same timing tests as described
in my posting 'Strange execution times' with mySQL.

There's no reason to whine about the 300 microseconds
at 100 selects. MySQL, connected by mysqltcl to Tcl, delivers
after about 26305 microseconds, decreasing for 1
runs to about 232 microseconds.

I'll definitely switch to sqlite! Thanks, Richard.

This is just for your information.

Kind regards

Ulrich

[sqlite] How to set affinity mode to "strict affinity"

[Jarl Friis]

Hi.

Can anyone tell me how to control the affinity mode?

Affinity mode is described on 
http://www.sqlite.org/datatype3.html (section 6 "Other Affinity
Modes")

Jarl

[sqlite] what if sqlite_finalize() fails?

[Michael Knigge]

All,

I wonder what I have to do if sqlite_finalize() fails? sqlite_close() 
will fail if there are any prepared statements associated with a 
database handle - so I can't close.


Due to the manual, sqlite_finalize() could return SQLITE_ABORT - do I 
have to call sqlite_finalize() again in this case?




Thanks,
  Michael

Re: [sqlite] Strange execution times

[Ulrich Schöbel]

Hi Ran,

no, sorry. It's running on a normal Linux PC, runnning 24/7.
No laptop, no stepping up. Time calculation is probably
a bit less accurate in the lower regions, but not that much.

It's really a mind boggler.

Thanks and kind regards

Ulrich


On Wednesday 22 February 2006 11:27, Ran wrote:
> Could it be connected to the stepping up of the CPU? Do you run those tests
> on a laptop? This at least could explain how the many iterations are faster
> (the CPU has time to step up).
> It does not explain why the 10 and 5 are fast as well (maybe when doing few
> iterations, the time calculation is less accurate), but mmm... maybe it
> could explain part of the phenomena?
>
> Ran
>
> On 2/22/06, Ulrich Schöbel <[EMAIL PROTECTED]> wrote:
> > Hi Adrian,
> >
> > I tried your script and got, after a slight modification, quite
> > consistent results. When I tried it as is, I got slightly varying
> > time results with a peak in the 50 to 100 region. Then I
> > commented out all lines concerning the deletion, creation
> > and filling to get the pure retrieval times. Drom then on
> > I got the following almost invariable results,
> >
> > t(1)=538 microseconds per iteration
> > t(5)=69.2 microseconds per iteration
> > t(10)=39.9 microseconds per iteration
> > t(50)=391.48 microseconds per iteration
> > t(100)=215.61 microseconds per iteration
> > t(500)=73.154 microseconds per iteration
> > t(1000)=54.753 microseconds per iteration
> > t(5000)=40.9094 microseconds per iteration
> > t(1)=39.4558 microseconds per iteration
> >
> > The t(1) time is probably due to Tcls bytecode engine, but
> > the t(50) and t(100) times are inexplicable, at least for me.
> >
> > The 'mini database' you use is, apart from a few additional
> > fields, almost identical to the one I used in my previous tests.
> >
> > Do you come to similar results?
> >
> > I have to oppose your statement, Tcl has garbage collection.
> > It doesn't, at least in the sense, that it calls a routine to
> > collect unused space and free it at arbitrary times, i.e. during
> > idle times. Tcl collects its garbage when there is some. Tcls
> > objects are reference counted and as soon as this count
> > reaches zero the object is cleaned up. This costs time, of
> > course, but it happens each time the garbage is due. That
> > has the effect, that garbage collection times are simply
> > included in execution times, regularly. It should not produce
> > the peak times I see at t(50) and t(100).
> >
> > Thanks for your help
> >
> > Ulrich
> >
> > On Wednesday 22 February 2006 02:45, Adrian Ho wrote:
> > > On Wed, Feb 22, 2006 at 01:13:19AM +0200, Ulrich Sch??bel wrote:
> > > > I don't think it's an interface problem. I'm using Tcl, more or less
> > > > the 'natural' language for sqlite. Tcl doesn't have a garbage
> > > > collection.
> > >
> > > Tcl certainly *does* have garbage collection:
> > >
> > > 
> > > 
> > >
> > > > The strangest thing is, I can reproduce this behaviour.
> > > > I'm absolutely clueless. I stumbled over it by coincidence.
> > > > Tried 1000 repetitions, was quite fast, so I tried 1,
> > > > which was even faster. This led me to the (obviously wrong)
> > > > conclusion, that sqlite spends some time parsing the sql.
> > > > Next I tried 100 repetitions, expecting a bit more than
> > > > 76 microseconds. 310 microsecs didn't bother me really,
> > > > I tried the 10 reps expecting even more. Then came the surprise:
> > > > only 67 microsecs.
> > > >
> > > > My first feeling was, something like a busy disk or so came
> > > > in just when I tried the 100 reps. But the results were reproducible,
> > > > deviating only by a few microseconds.
> > >
> > > Try running the following script and see if there's an odd pattern to
> > > the timing variations:
> > >
> > > #!/usr/bin/env tclsh
> > > package require sqlite3
> > > if {[file exists aho.db]} {
> > >   file delete aho.db
> > > }
> > > sqlite3 db aho.db
> > > db eval {create table cust_persons ( first_name string, last_name
> > > string )}
> > > db eval {insert into cust_persons values ('Adrian','Ho')}
> > > db eval {insert into cust_persons values ('Thunder','Lightning')}
> > > foreach rounds {1 5 10 50 100 500 1000 5000 1} {
> > >   puts "t($rounds)=[time {db eval {select * from cust_persons where
> > > first_name = 'Adrian'}} $rounds]" }
> > > db close
> > >
> > > - Adrian

Re: [sqlite] Strange execution times

[Ran]

Could it be connected to the stepping up of the CPU? Do you run those tests
on a laptop? This at least could explain how the many iterations are faster
(the CPU has time to step up).
It does not explain why the 10 and 5 are fast as well (maybe when doing few
iterations, the time calculation is less accurate), but mmm... maybe it
could explain part of the phenomena?

Ran

On 2/22/06, Ulrich Schöbel <[EMAIL PROTECTED]> wrote:
>
> Hi Adrian,
>
> I tried your script and got, after a slight modification, quite
> consistent results. When I tried it as is, I got slightly varying
> time results with a peak in the 50 to 100 region. Then I
> commented out all lines concerning the deletion, creation
> and filling to get the pure retrieval times. Drom then on
> I got the following almost invariable results,
>
> t(1)=538 microseconds per iteration
> t(5)=69.2 microseconds per iteration
> t(10)=39.9 microseconds per iteration
> t(50)=391.48 microseconds per iteration
> t(100)=215.61 microseconds per iteration
> t(500)=73.154 microseconds per iteration
> t(1000)=54.753 microseconds per iteration
> t(5000)=40.9094 microseconds per iteration
> t(1)=39.4558 microseconds per iteration
>
> The t(1) time is probably due to Tcls bytecode engine, but
> the t(50) and t(100) times are inexplicable, at least for me.
>
> The 'mini database' you use is, apart from a few additional
> fields, almost identical to the one I used in my previous tests.
>
> Do you come to similar results?
>
> I have to oppose your statement, Tcl has garbage collection.
> It doesn't, at least in the sense, that it calls a routine to
> collect unused space and free it at arbitrary times, i.e. during
> idle times. Tcl collects its garbage when there is some. Tcls
> objects are reference counted and as soon as this count
> reaches zero the object is cleaned up. This costs time, of
> course, but it happens each time the garbage is due. That
> has the effect, that garbage collection times are simply
> included in execution times, regularly. It should not produce
> the peak times I see at t(50) and t(100).
>
> Thanks for your help
>
> Ulrich
>
> On Wednesday 22 February 2006 02:45, Adrian Ho wrote:
> > On Wed, Feb 22, 2006 at 01:13:19AM +0200, Ulrich Sch??bel wrote:
> > > I don't think it's an interface problem. I'm using Tcl, more or less
> > > the 'natural' language for sqlite. Tcl doesn't have a garbage
> > > collection.
> >
> > Tcl certainly *does* have garbage collection:
> >
> > 
> > 
> >
> > > The strangest thing is, I can reproduce this behaviour.
> > > I'm absolutely clueless. I stumbled over it by coincidence.
> > > Tried 1000 repetitions, was quite fast, so I tried 1,
> > > which was even faster. This led me to the (obviously wrong)
> > > conclusion, that sqlite spends some time parsing the sql.
> > > Next I tried 100 repetitions, expecting a bit more than
> > > 76 microseconds. 310 microsecs didn't bother me really,
> > > I tried the 10 reps expecting even more. Then came the surprise:
> > > only 67 microsecs.
> > >
> > > My first feeling was, something like a busy disk or so came
> > > in just when I tried the 100 reps. But the results were reproducible,
> > > deviating only by a few microseconds.
> >
> > Try running the following script and see if there's an odd pattern to
> > the timing variations:
> >
> > #!/usr/bin/env tclsh
> > package require sqlite3
> > if {[file exists aho.db]} {
> >   file delete aho.db
> > }
> > sqlite3 db aho.db
> > db eval {create table cust_persons ( first_name string, last_name string
> > )}
> > db eval {insert into cust_persons values ('Adrian','Ho')}
> > db eval {insert into cust_persons values ('Thunder','Lightning')}
> > foreach rounds {1 5 10 50 100 500 1000 5000 1} {
> >   puts "t($rounds)=[time {db eval {select * from cust_persons where
> > first_name = 'Adrian'}} $rounds]" }
> > db close
> >
> > - Adrian
>

Re: [sqlite] Strange execution times

[Ulrich Schöbel]

Hi Adrian,

I tried your script and got, after a slight modification, quite
consistent results. When I tried it as is, I got slightly varying
time results with a peak in the 50 to 100 region. Then I
commented out all lines concerning the deletion, creation
and filling to get the pure retrieval times. Drom then on
I got the following almost invariable results,

t(1)=538 microseconds per iteration
t(5)=69.2 microseconds per iteration
t(10)=39.9 microseconds per iteration
t(50)=391.48 microseconds per iteration
t(100)=215.61 microseconds per iteration
t(500)=73.154 microseconds per iteration
t(1000)=54.753 microseconds per iteration
t(5000)=40.9094 microseconds per iteration
t(1)=39.4558 microseconds per iteration

The t(1) time is probably due to Tcls bytecode engine, but
the t(50) and t(100) times are inexplicable, at least for me.

The 'mini database' you use is, apart from a few additional
fields, almost identical to the one I used in my previous tests.

Do you come to similar results?

I have to oppose your statement, Tcl has garbage collection.
It doesn't, at least in the sense, that it calls a routine to
collect unused space and free it at arbitrary times, i.e. during
idle times. Tcl collects its garbage when there is some. Tcls
objects are reference counted and as soon as this count
reaches zero the object is cleaned up. This costs time, of
course, but it happens each time the garbage is due. That
has the effect, that garbage collection times are simply
included in execution times, regularly. It should not produce
the peak times I see at t(50) and t(100).

Thanks for your help

Ulrich

On Wednesday 22 February 2006 02:45, Adrian Ho wrote:
> On Wed, Feb 22, 2006 at 01:13:19AM +0200, Ulrich Sch??bel wrote:
> > I don't think it's an interface problem. I'm using Tcl, more or less
> > the 'natural' language for sqlite. Tcl doesn't have a garbage
> > collection.
>
> Tcl certainly *does* have garbage collection:
>
> 
> 
>
> > The strangest thing is, I can reproduce this behaviour.
> > I'm absolutely clueless. I stumbled over it by coincidence.
> > Tried 1000 repetitions, was quite fast, so I tried 1,
> > which was even faster. This led me to the (obviously wrong)
> > conclusion, that sqlite spends some time parsing the sql.
> > Next I tried 100 repetitions, expecting a bit more than
> > 76 microseconds. 310 microsecs didn't bother me really,
> > I tried the 10 reps expecting even more. Then came the surprise:
> > only 67 microsecs.
> >
> > My first feeling was, something like a busy disk or so came
> > in just when I tried the 100 reps. But the results were reproducible,
> > deviating only by a few microseconds.
>
> Try running the following script and see if there's an odd pattern to
> the timing variations:
>
> #!/usr/bin/env tclsh
> package require sqlite3
> if {[file exists aho.db]} {
>   file delete aho.db
> }
> sqlite3 db aho.db
> db eval {create table cust_persons ( first_name string, last_name string
> )}
> db eval {insert into cust_persons values ('Adrian','Ho')}
> db eval {insert into cust_persons values ('Thunder','Lightning')}
> foreach rounds {1 5 10 50 100 500 1000 5000 1} {
>   puts "t($rounds)=[time {db eval {select * from cust_persons where
> first_name = 'Adrian'}} $rounds]" }
> db close
>
> - Adrian