Hi Tim & Team,

I'm running a basic query using a client / server set-up (in fact at the
moment they are both on the SAME PC, so not even across the LAN as such.

Anyway, when I run the query, initially it's sometimes slow. Then if I
UNPREPARE it and run it again, it's nice and snappy.

I have found this a few times, and wonder what would cause it to happen?

Once its run slow I can close the EDB Manager and the server program,
then run them again and execute the query and it's still snappy...
However now and then when I run it, its slow.

The PLAN below is when it ran snappy. I initially noticed this slow down
in my program when it took ages for the report to show and then ran the
report again and it was quick. Initially thinking it was the report, I
tested running it using the EDB Manager with my server program and did
find it was slow on occasion.

Any ideas?

================================================================================
SQL Query (Executed by ElevateDB 2.08 Build 3)

Note: The SQL  shown here is generated by ElevateDB and may not be
exactly the
same as the SQL that was originally entered.  However, none of the
differences
alter the execution results in any way.
================================================================================

SELECT ALL
"reservation"."companyID" AS "companyID",
"company"."comp_name" AS "comp_name",
"company"."city" AS "city",
"company"."state" AS "state",
"company"."companyemail" AS "companyemail",
SUM("trans"."trans_total") AS "balance"
FROM "reservation" INNER JOIN "company" ON "reservation"."companyID" =
"company"."companyID",
INNER JOIN "trans" ON "reservation"."res_num" = "trans"."res_num"
WHERE "reservation"."status" = 40
GROUP BY "reservation"."companyID"
HAVING SUM("trans"."trans_total") >= 0.01
ORDER BY "company"."comp_name"

Source Tables
-------------

reservation: 34796 rows
company: 2962 rows
trans: 158374 rows

Result Set
----------

The result set was insensitive and read-only
The result set consisted of zero or more rows

Filtering
---------

The following filter condition was applied to the reservation table:

"reservation"."status" = 40

Index scan (reservation.status): 33575 keys, 532480 bytes estimated cost

Joins
-----

The driver table was the reservation table

The reservation table was joined to the company table with the inner join
expression:

"reservation"."companyID" = "company"."companyID"

The reservation table was joined to the trans table with the inner join
expression:

"reservation"."res_num" = "trans"."res_num"

The optimizer attempted to re-order the joins to a more optimal order

The optimizer successfully re-ordered the joins into this more optimal
order:

The driver table was the company table

The company table was joined to the reservation table with the inner join
expression:

"reservation"."companyID" = "company"."companyID"

The reservation table was joined to the trans table with the inner join
expression:

"trans"."res_num" = "reservation"."res_num"

The following join condition was applied to the reservation table:

"reservation"."companyID" = "company"."companyID"

Index scan (reservation.companyID)

The following join condition was applied to the trans table:

"trans"."res_num" = "reservation"."res_num"

Index scan (trans.resnum)


Result set I/O statistics
-------------------------

Total rows visited: 84899

Row buffer manager

Max buffer size: 1048496 Buffer size: 869744

Hits: 257496   Misses: 0   Hit ratio: 1

Reads: 0   Bytes read: 0

Writes: 1   Bytes written: 395504

Index Page buffer manager

Max buffer size: 2097152 Buffer size: 368640

Hits: 140384   Misses: 0   Hit ratio: 1

Reads: 0   Bytes read: 0

Writes: 1   Bytes written: 172032

================================================================================
31 row(s) returned in 3.432 secs
================================================================================

Phil


Tim may be able to provide a definitive answer, but if its the same query running against the same data then its unlikely to be anything to do with the engine or its optimisation (unless its just having a "bad hair day"). More likely are other factors - in no particular just as it occurs to me:

1. moving from single user access to multi-user access causing the infamous Windows slowdown effect (read these ngs and you'll find it referred to a bit)

2. Other apps running on the PC

3. Buffering (both ElevateDB & Windows) - I have managed to achieve some serious differences in query run times because of this.

4. Anti virus deciding to play

5. Windows housekeeping

6. Accessing the internet

Understanding performance on a Windows PC is a non trivial task these days. Being an old fart I can remember the days when you set up an app and then raced round a load of terminals hitting the enter button as quick as you could to simulate normal usage - worked pretty well.

Roy Lambert [Team Elevate]

Thanks Roy,

I just tried again after the server / EDB Manager was closed down for
several hours. This time instead of using my Server app I used the
Elevate DB Server to see if it might be my server program causing the
slow down...

But like clock work it went slow again, so it's definitely not my server
program or client program as I was using the Elevate programs.

While it was taking ages, I opened up the task manager and nothing had
ANY CPU usage accept the Elevate DB Server program which was going
between 1 - 3 % which was low.

The same query took 62 seconds as oppose to it usually taking just 3
seconds.

Once again, afterwards I Unprepared the query, ran it again and it took
just 3 seconds as in the previous post. I'm pretty certain its not
anything like the anti virus, internet, email etc as nothing was
accessing the internet and its far to consistent. When it runs slow it's
always 62 seconds and when it runs fast it 3 seconds.

Here's the Execution plan when it went slow:

================================================================================
SQL Query (Executed by ElevateDB 2.08 Build 3)

Note: The SQL  shown here is generated by ElevateDB and may not be
exactly the
same as the SQL that was originally entered.  However, none of the
differences
alter the execution results in any way.
================================================================================

SELECT ALL
"reservation"."companyID" AS "companyID",
"company"."comp_name" AS "comp_name",
"company"."city" AS "city",
"company"."state" AS "state",
"company"."companyemail" AS "companyemail",
SUM("trans"."trans_total") AS "balance"
FROM "reservation" INNER JOIN "company" ON "reservation"."companyID" =
"company"."companyID",
INNER JOIN "trans" ON "reservation"."res_num" = "trans"."res_num"
WHERE "reservation"."status" = 40
GROUP BY "reservation"."companyID"
HAVING SUM("trans"."trans_total") >= 0.01
ORDER BY "company"."comp_name"

Source Tables
-------------

reservation: 34796 rows
company: 2962 rows
trans: 158374 rows

Result Set
----------

The result set was insensitive and read-only
The result set consisted of zero or more rows

Filtering
---------

The following filter condition was applied to the reservation table:

"reservation"."status" = 40

Index scan (reservation.status): 33575 keys, 532480 bytes estimated cost

Joins
-----

The driver table was the reservation table

The reservation table was joined to the company table with the inner join
expression:

"reservation"."companyID" = "company"."companyID"

The reservation table was joined to the trans table with the inner join
expression:

"reservation"."res_num" = "trans"."res_num"

The optimizer attempted to re-order the joins to a more optimal order

The optimizer successfully re-ordered the joins into this more optimal
order:

The driver table was the company table

The company table was joined to the reservation table with the inner join
expression:

"reservation"."companyID" = "company"."companyID"

The reservation table was joined to the trans table with the inner join
expression:

"trans"."res_num" = "reservation"."res_num"

The following join condition was applied to the reservation table:

"reservation"."companyID" = "company"."companyID"

Index scan (reservation.companyID)

The following join condition was applied to the trans table:

"trans"."res_num" = "reservation"."res_num"

Index scan (trans.resnum)


Result set I/O statistics
-------------------------

Total rows visited: 84899

Row buffer manager

Max buffer size: 1048496 Buffer size: 869744

Hits: 257496   Misses: 0   Hit ratio: 1

Reads: 0   Bytes read: 0

Writes: 1   Bytes written: 395504

Index Page buffer manager

Max buffer size: 2097152 Buffer size: 368640

Hits: 140384   Misses: 0   Hit ratio: 1

Reads: 0   Bytes read: 0

Writes: 1   Bytes written: 172032

================================================================================
31 row(s) returned in 62.806 secs
================================================================================

Phil

Is it always the first run that's slow? If so it could be something opening up in the database eg if any of your tables were actually views, dirty great wadges of triggers or something. You may note I'm guessing here

Roy Lambert [Team Elevate]

Hi Roy,

I've found if I reboot the PC the first time I run the query it's slow
and then when I unprepare and execute again its fast.

I have no views, procedures, functions or triggers in the database.

I also just tried dropping the database / session, deleting the physical
catalog / database files and then recreating and restoring... Then
rebooted and ran the query and it was slow again. Then after unpreparing
it was fast as. I can close the programs down, run them and it appears
to be fast, only appears after a reboot.

Any ideas?

Thanks again,

Phil.

Only additional information I can think that might be useful is...

The database was migrated from a DBISAM 4 database.

I'm using Version 2.08 Build UNICODE.

Doh, that was meant to read... Version 2.08 Build 3 UNICODE.

Phil

>I've found if I reboot the PC the first time I run the query it's slow
>and then when I unprepare and execute again its fast.
>
>I have no views, procedures, functions or triggers in the database.
>
>I also just tried dropping the database / session, deleting the physical
>catalog / database files and then recreating and restoring... Then
>rebooted and ran the query and it was slow again. Then after unpreparing
>it was fast as. I can close the programs down, run them and it appears
>to be fast, only appears after a reboot.

That, I think, moves it out of the realm of ElevateDB and into the realm of Windows / AV / hardware.

Preparing a query (to the best of my knowledge) essentially parses the code, building the parameter list if necessary, and opens the tables involved. Unpreparing it releases the file handles but (I think) doesn't dispose of them. Slow after a reboot only could mean that on first open AV software is scanning the whole table causing the slowdown and for the second open it recognises its checked it and doesn't bother.

Try disabling your AV and rebooting and see what happens.

Roy Lambert [Team Elevate]

Sounds like OS level caching difference - query does seem to involve
some amount that needs to be read from disk and since result set is
insensitive it needs to create a temporary tables on disk as well.

This would not be cpu intensive but would take time to read all the data
from tables; after initial run the OS would cache lot of this so
subsequent runs are fast - even if your app is closed and reopened the
OS cache might still be valid even for edbmanager.

Don't have much advise to give though on how to avoid it - other than
using SSD drive that might help.

In cases like these I i run run the subqueries making up the main query
to better identify wheret he biggest slowdown and then seeing if
alternate query might work faster. Hopefully others have better
suggestions and you can always ask Tim directly to look at it (thru
support email)


Raul


On 6/17/2012 5:21 AM, Phil wrote:
> Thanks Roy,
>
> I just tried again after the server / EDB Manager was closed down for
> several hours. This time instead of using my Server app I used the
> Elevate DB Server to see if it might be my server program causing the
> slow down...
>
> But like clock work it went slow again, so it's definitely not my server
> program or client program as I was using the Elevate programs.
>

Thanks Roy and Raul,

I booted up, disabled all AV / protection software then tried again and
got the same slow result the first time, infact this time the query took
124 seconds which is crazy when I can unprepare and run the query for
the second time and get the result in 3 seconds.

I thought I'd experiment and try the DBISAM database with identical data
in it, that contained the originally migrated data.

On the initial run it took 31 seconds, then after unpreparing and
running again it took 3 seconds. (so DBISAM in this instance at least
takes one 30 seconds compared with ElevateDB initially taking 60 - 124
seconds.

Surely there would have to be a way around this. Many of my users would
run the software, go to do a report and have to wait up to 2 minutes for
a report that would normally take just 3 seconds.

I'm puzzled. I do understand what Raul said about Windows caching, but I
would think there has to be a way around this.

Thanks again,

Phil.