(Very) Slow raw SQL queries

[Mehmet A.]

Hi,

db.executesql() takes 30 seconds to return a result while page-loading, despite the fact that same query takes 0.5-1 second if I try it on MySQL console or web2py debug console or web2py shell.

[4] dbs._timings
[('SELECT 1;', 0.016000032424926758),
 ('SET FOREIGN_KEY_CHECKS=1;', 0.003999948501586914),
 ("SET sql_mode='NO_BACKSLASH_ESCAPES';", 0.00800013542175293),
 ("SELECT TIMESTAMPDIFF(...) AS 'duration',\n
         TIMESTAMPDIFF(...)\n
                - INTERVAL 1 HOUR, TIMESTAMP(...)\n
                + INTERVAL CAST(...) AS 'timediff',\n
         ris.ODATE as 'date',\n
         CONCAT(...) as 'service'\n
    FROM ... AS ris\n
    JOIN ... as sd on ris.... = sd....\n
    WHERE ris.... != '0000-00-00 00:00:00'\n
          and ris.... != '0000-00-00 00:00:00'\n
          and ris.... >= '2010-8-15'\n
          and ris.... <= '2014-8-22'", 32.0460000038147),

 ("SELECT TIMESTAMPDIFF(...) AS 'duration',\n
         TIMESTAMPDIFF(...)\n
                - INTERVAL 1 HOUR, TIMESTAMP(...)\n
                + INTERVAL CAST(...) AS 'timediff',\n
         ris.ODATE as 'date',\n
         CONCAT(...) as 'service'\n
    FROM ... AS ris\n
    JOIN ... as sd on ris.... = sd....\n
    WHERE ris.... != '0000-00-00 00:00:00'\n
          and ris.... != '0000-00-00 00:00:00'\n
          and ris.... >= '2010-8-15'\n
          and ris.... <= '2014-8-22'", 0.6069998741149902)]

The query that took 32 seconds was executed with the page request. The controller was falling to the debug console after db.executesql(), so the second query which took 0.6 second was executed by me on the same session.

[Cliff Kachinske]

Why is '\n', the newline character, sprinkled throughout your query?

See what happens if you get rid of them.

[Derek]

I believe the timings did that, it's not in the query.

[Derek]

so here is his code...

SELECT TIMESTAMPDIFF(...) AS 'duration',

         TIMESTAMPDIFF(...)

                - INTERVAL 1 HOUR, TIMESTAMP(...)

                + INTERVAL CAST(...) AS 'timediff',

         ris.ODATE as 'date',
         CONCAT(...) as 'service'
    FROM ... AS ris

    JOIN ... as sd on ris.... = sd....

    WHERE ris.... != '0000-00-00 00:00:00'

          and ris.... != '0000-00-00 00:00:00'

          and ris.... >= '2010-8-15'
          and ris.... <= '2014-8-22'

so the timing for that is:  32.0460000038147

as far as what are the differences, well, web2py does open a transaction and then close the transaction...

On Monday, August 25, 2014 9:24:41 AM UTC-7, Cliff Kachinske wrote:

[Mehmet A.]

It's in the query, it's because of I used triple-quotes while constructing the query. I tried removing them, didn't help. I can't even reproduce it on the console.

...
raw_data = dbs.executesql(query, as_dict=True) #Takes more than 30 seconds
from gluon.debug import dbg
dbg.set_trace()
#Debug starts here
raw_data = dbs.executesql(query, as_dict=True) #Takes less than 1s

or

...
from gluon.debug import dbg
dbg.set_trace()
#Debug starts here
raw_data = dbs.executesql(query, as_dict=True) #Again, it takes less than 1s

[Mehmet A.]

Hello Derek. Yesterday I replied to the discussion but my post never made it to the public, don't know why.

Newline characters are indeed in the queries. They're there because I used triple-quotes to create query string. I also tried removing them, didn't help.

And I can't reproduce the slowness on the console. This makes me wonder about a potential bug.

I tried following cases:

...
raw_data = dbs.executesql(query, as_dict=True) #Takes 30 seconds to return a result

from gluon.debug import dbg
dbg.set_trace()

raw_data = dbs.executesql(query, as_dict=True) #Takes <1 second to return a result

or

...
from gluon.debug import dbg
dbg.set_trace()

raw_data = dbs.executesql(query, as_dict=True) #Takes <1 second to return a result