Google Groups no longer supports new Usenet posts or subscriptions. Historical content remains viewable.
Dismiss

[Info-Ingres] IMA query duration

5 views
Skip to first unread message

Robert Allely

unread,
Jul 29, 2010, 5:13:36 PM7/29/10
to Ingres and related product discussion forum
Is there any information in IMA about when a query started? It would be nice to be able to detect long-running queries
 
-Robert
 
 

 

Confidentiality/Privilege Notice:
This communication is confidential and may be legally privileged.  If you are not the intended recipient please delete the message and notify the sender at Ports of Auckland Limited. Any use, disclosure, copying, distribution or retention of this communication is strictly prohibited.

Karl Schendel

unread,
Jul 29, 2010, 5:20:16 PM7/29/10
to Ingres and related product discussion forum
Not that I know of, no.

Unlike most IMA requests I see, this one might even be feasible. :) But
I am pretty sure that no facility tracks query start times at the moment.

Karl

glennr69

unread,
Jul 31, 2010, 12:17:03 AM7/31/10
to
Hi Robert

I have an abf procedure that runs every xx seconds that creates a temp
table containing the currently executing SQL and then when it wakes up
again it compares current with what's in the temp table.

If it finds the same SQL then it sends a email containing the slow
SQL... It's not 100% as sometimes it picks up statements like
"commit" but it's pretty useful...

The code is below (it could also be run as a SQL script just as
easily)...

procedure imaslowsql
(
exit_loop = integer2 not null with default
, loop_time = integer4 not null with default
, session_id = varchar(32) not null with default
, effective_user = varchar(32) not null with default
, db_name = varchar(32) not null with default
, session_query = varchar(1000) not null with default
, client_info = varchar(64) not null with default
, sys_cmd = varchar(2000) not null with default
, h_params = varchar(100) not null with default
, event = varchar(24) not null with default
, owner = varchar(24) not null with default
, db = varchar(24) not null with default
, evdate = varchar(25) not null with default
, eventtxt = varchar(100) not null with default
) =
{
sccs_id := '%E% %W% F&P';
callproc ing_dberr ();

h_params = CALLPROC CommandLineParameters();

loop_time := int4(:h_params);

CALLPROC printmsg ('IMASLOWSQL: Starting at ' +
squeeze(char(date('now'))));
CALLPROC printmsg ('IMASLOWSQL: Loop time set to: ' +
ascii(:loop_time) + ' seconds');
exit_loop := 0;

/* Create some dbevents so we can stop easily */

DROP DBEVENT imaslowsql_shutdown;
COMMIT;
CREATE DBEVENT imaslowsql_shutdown;
COMMIT;

/* Now register for the imaslowsql_shutdown event */

REGISTER DBEVENT imaslowsql_shutdown;
COMMIT;

execute procedure ima_set_vnode_domain;

/* Drop old slow sql tables just incase ! */

DROP session.imaslowsql_current_sql;
COMMIT;
DROP session.imaslowsql_previous_sql;
COMMIT;

/* Create the current sql table */

DECLARE GLOBAL TEMPORARY TABLE session.imaslowsql_current_sql AS
SELECT session_id
, effective_user
, db_name
, session_query
, client_info
FROM ima_server_sessions
WHERE session_query != ''
AND db_name != 'imadb' /* Dont select querys on imadb */
ON COMMIT PRESERVE ROWS
WITH NORECOVERY;

CALLPROC fap_errhan (en = byref(:en), rc = byref(:rc), em =
byref(:em));
IF en != 0 THEN
CALLPROC printmsg ('IMASLOWSQL: Error creating
imaslowsql_current_sql');
RETURN;
ENDIF;
COMMIT;

CALLPROC printmsg ('IMASLOWSQL: Starting Loop');

WHILE ( :exit_loop = 0 ) DO

sleep :loop_time;

/* Copy the current sql table to the previous */

DROP TABLE session.imaslowsql_previous_sql;
COMMIT;

DECLARE GLOBAL TEMPORARY TABLE session.imaslowsql_previous_sql AS
SELECT *
FROM session.imaslowsql_current_sql
ON COMMIT PRESERVE ROWS
WITH NORECOVERY;

CALLPROC fap_errhan (en = byref(:en), rc = byref(:rc), em =
byref(:em));
IF en != 0 THEN
CALLPROC printmsg ('IMASLOWSQL: Error creating
imaslowsql_previous_sql');
RETURN;
ENDIF;
COMMIT;

/* Recreate the current sql table */
DROP session.imaslowsql_current_sql;
COMMIT;

DECLARE GLOBAL TEMPORARY TABLE session.imaslowsql_current_sql AS
SELECT session_id
, effective_user
, db_name
, session_query
, client_info
FROM ima_server_sessions
WHERE session_query != ''
AND db_name != 'imadb' /* Dont select querys on imadb
*/
ON COMMIT PRESERVE ROWS
WITH NORECOVERY;

CALLPROC fap_errhan (en = byref(:en), rc = byref(:rc), em =
byref(:em));
IF en != 0 THEN
CALLPROC printmsg ('IMASLOWSQL: Error creating
imaslowsql_current_sql');
RETURN;
ENDIF;
COMMIT;

/* Now lets see if there are any queries still running */

SELECT session_id = c.session_id
, effective_user = c.effective_user
, db_name = c.db_name
, session_query = c.session_query
, client_info = c.client_info
FROM session.imaslowsql_current_sql c
, session.imaslowsql_previous_sql p
WHERE c.session_id = p.session_id
AND c.db_name = p.db_name
AND c.session_query = p.session_query
AND c.effective_user = p.effective_user
{
/* If there are any still running, email them to fpfdba */

CALLPROC printmsg ('IMASLOWSQL: Slow query found at ' +
squeeze(char(date('now'))));

sys_cmd := '/bin/printf ' + '"' + 'Query ran over ' +
ascii(:loop_time) + '\n' + 'CLIENT DETAILS: ' + :client_info + '\n' +
'QUERY: ' + :session_query + '"' + ' | /bin/mailx -s "' + 'IMASLOWSQL
Report"' + ' fpfdba@midas';

CALL SYSTEM :sys_cmd;

};

/* Check to see if the imaslowsql_shutdown dbevent has been raised
*/

GET DBEVENT;

INQUIRE_SQL( event = dbeventname
, owner = dbeventowner
, db = dbeventdatabase
, evdate = dbeventtime
, eventtxt = dbeventtext);

COMMIT;

IF event = 'imaslowsql_shutdown' THEN

CALLPROC printmsg ('IMASLOWSQL: Shutdown dbevent found - exiting
loop');
exit_loop := 1;

ENDIF;


ENDWHILE;

CALLPROC printmsg ('IMASLOWSQL: Stopping at ' +
squeeze(char(date('now'))));

RETURN;

Karl Schendel

unread,
Jul 31, 2010, 9:57:12 AM7/31/10
to Ingres and related product discussion forum

On Jul 31, 2010, at 12:17 AM, glennr69 wrote:

> Hi Robert
>
> I have an abf procedure that runs every xx seconds that creates a temp
> table containing the currently executing SQL and then when it wakes up
> again it compares current with what's in the temp table.
>
> If it finds the same SQL then it sends a email containing the slow
> SQL... It's not 100% as sometimes it picks up statements like
> "commit" but it's pretty useful...

Indeed. I've used this idea by hand, just hitting "Refresh" while in
IPM -> server -> sessions, and it definitely qualifies as Crude,
but Surprisingly Effective. Doing it from a background procedure
is a nice idea.

Karl


Ingres Forums

unread,
Aug 9, 2010, 10:34:07 AM8/9/10
to

I also consider this a nice idea and want to try it out but have
difficulties with it. In the code there is...

callproc ing_dberr ();
h_params = CALLPROC CommandLineParameters();
.. but it seems both procedures ing_dberr and CommandLineParameters
are not defined anywhere in the code.

I'm also unsure about how to use it. I have saved your into a file
slowqueries.sql, then have run
isql imadb, then have loaded the file into isql and tried to execute
it. Sould it be used that way...?

TIA
Gerhard


--
gerhard...@planat.de
------------------------------------------------------------------------
gerhard...@planat.de's Profile: http://community.ingres.com/forum/member.php?userid=857
View this thread: http://community.ingres.com/forum/showthread.php?t=12397

Ingres Forums

unread,
Aug 10, 2010, 5:49:17 AM8/10/10
to

I rewrote the code above so I can actually understand it - the
"beautified" code is at 'SQL | PROCEDURE imaslowsql ( e - Dejan Lekic -
fzBcJfvs - Pastebin.com' (http://ingres.pastebin.com/fzBcJfvs) .

glennr69's code uses an old approach explained in couple of articles
and presentations ("identifying long-running queries", etc)...


--
dejan
------------------------------------------------------------------------
dejan's Profile: http://community.ingres.com/forum/member.php?userid=13077

Ingres Forums

unread,
Aug 11, 2010, 3:40:44 AM8/11/10
to

Hello Dejan,
thanks for this. I saved your code into a file imaslowsql.sql, ran an
"isql imadb", loaded the file into the isql session and fired it up with
F9(Go).

I got this error message:
E_US096D Local variable/parameter 'sccs_id' has not been declared or
is
out of scope.

Can you give me a further hint?

TIA
Gerhard


--
gerhard...@planat.de
------------------------------------------------------------------------
gerhard...@planat.de's Profile: http://community.ingres.com/forum/member.php?userid=857

Ingres Forums

unread,
Aug 11, 2010, 5:57:07 AM8/11/10
to

Hi

I have used a similar approach.
An ESQLC-program with a loop that inserts the running queries in a
table. I keep the queries running longer than a particular time interval
in the table, so I can run reports on it later.
I apply the same approach to get queries locking other queries longer
than a specified time.
I presented my approach on the IUA in London last June, so my
presentation should be available on the IUA website.

PostgreSQL has a parameter in the configuration file that says to log
queries taking longer than a number of milliseconds
(log_min_duration_statement). It would certainly be nice to have
something like that in Ingres. It wouldn't probably be very difficult
adding an parameter to the SC930 trace point (query recording) to
specify a number of milliseconds. ;-)

Best regards
Frédéric


--
fba
------------------------------------------------------------------------
fba's Profile: http://community.ingres.com/forum/member.php?userid=16637

Gerhard Hofmann

unread,
Aug 11, 2010, 6:22:53 AM8/11/10
to
On 11 Aug., 11:57, Ingres Forums <info-

ing...@kettleriverconsulting.com> wrote:
> Hi
>
> I have used a similar approach.
> An ESQLC-program with a loop that inserts the running queries in a
> table. I keep the queries running longer than a particular time interval
> in the table, so I can run reports on it later.
> I apply the same approach to get queries locking other queries longer
> than a specified time.
> I presented my approach on the IUA in London last June, so my
> presentation should be available on the IUA website.
>
> PostgreSQL has a parameter in the configuration file that says to log
> queries taking longer than a number of milliseconds
> (log_min_duration_statement). It would certainly be nice to have
> something like that in Ingres. It wouldn't probably be very difficult
> adding an parameter to the SC930 trace point (query recording) to
> specify a number of milliseconds. ;-)
>
> Best regards
> Frédéric
>

Unfortunately not here:
http://www.iua.org.uk/confindex.htm

Could you provide an alternative download link of the presentation?

TIA
Gerhard

Paul Mason

unread,
Aug 11, 2010, 7:13:38 AM8/11/10
to Ingres and related product discussion forum
SC930 outputs the query text at the very beginning of query execution, before optimization in fact so we don't even know how long we *think* it will take never mind how long it has taken. We could move it to the end of the query execution but then I think there's various information i.e. memory used, that we currently hand back once we done with that we'd need to hang on to. So we'd end up increasing the overhead. A config that's fine for a particular workload might now be too small for the same workload with SC930 turned on.

With SC930 we've always got one eye on what the potential impact/overhead/risk might be as it gets run in busy production environments - that tends to be where it comes into its own.

I think a better approach would be to add to/adapt the trace point sc924 mechanism that outputs query text if a particular error message is hit. You could have a new config parameter that specifies how long a "long query" is and if a query takes longer than that generate a new warning/error message. Then hard-code this new message alongside the check for the sc924 error code (you don't want to lose the ability to trigger on some other error).

It wouldn't be that big a job actually - nice little open source project if anyone's got the time?

Cheers
Paul

Ingres Forums

unread,
Aug 11, 2010, 3:23:44 PM8/11/10
to

Hi Gerhard

I will send you the presentation via e-mail.

BR
Frédéric


--
fba
------------------------------------------------------------------------

Ingres Forums

unread,
Aug 12, 2010, 4:28:53 AM8/12/10
to

Frederic,

I have sent you an e-mail asking for the source code from that
presentation. You have either ignored it, or did not receive it at all.
:) I think presentation was brilliant, but it would be really great if
source code is available somewhere so we do not have to write it again
and again...
It would be really great if you paste the code somewhere. 'Pastebin.com
- #1 paste tool since 2002!' (http://ingres.pastebin.com) is the place
where #ingres people paste their code snippets. So I recommend it
instead of thousands of other similar places.


--
dejan
------------------------------------------------------------------------
dejan's Profile: http://community.ingres.com/forum/member.php?userid=13077

Ingres Forums

unread,
Aug 12, 2010, 5:52:21 AM8/12/10
to

@Dejan

Well... I just got back from a 3-week holiday, so I haven't processed
all my e-mails yet, only the urgent ones. I remember seeing an e-mail
wrt to my presentation. :-) I'll try to do that as soon as I can.

I think it would be much better of course to have a trace point to log
long queries (and long locks...)?
Maybe I'll just have to join the code sprint next year. ;-)

@Mason
Wouldn't it be better to have a whole new trace point rather than risk
breaking sc924?


--
fba
------------------------------------------------------------------------
fba's Profile: http://community.ingres.com/forum/member.php?userid=16637

Paul Mason

unread,
Aug 12, 2010, 6:57:13 AM8/12/10
to Ingres and related product discussion forum
I think the risk to sc924 would be minimal and in any case the code that
actually outputs the query text is already called from lots of places
(it's part of a generic error output routine in uleformat.c) and
triggers on other error messages not just the sc924 - so it's already
shared in that sense.

I also think the benefit of re-using this is that if something changes -
e.g. I just did a fix to stop the text getting truncated in some
circumstances - then it only has to be changed in one place.

Paul

> -----Original Message-----
> From: info-ingr...@kettleriverconsulting.com [mailto:info-
> ingres-...@kettleriverconsulting.com] On Behalf Of Ingres Forums
> Sent: 12 August 2010 10:52
> To: info-...@kettleriverconsulting.com
> Subject: Re: [Info-Ingres] IMA query duration
>
>

Ingres Forums

unread,
Aug 12, 2010, 7:36:06 AM8/12/10
to

fba;33471 Wrote:
> Hi Gerhard
>
> I will send you the presentation via e-mail.
>
> BR
> Frédéric

Thanks a lot, have received it, it's very interesting.

Regards
Gerhard


--
gerhard...@planat.de
------------------------------------------------------------------------
gerhard...@planat.de's Profile: http://community.ingres.com/forum/member.php?userid=857

Robert Allely

unread,
Sep 13, 2010, 6:14:42 PM9/13/10
to Ingres and related product discussion forum
I originally raised this question, and then I coded some OpenROAD objects to do a similar thing to the ESQLC process mentioned below.

The queries that have been there a while are stored in an array, they are written out to a table when its decided that they are slow (number of seconds since first seen).
If they are in LOCK state the blocking lock is found , using the usual ima method.
It took a few hours to do but I already had all the ima sql setup , I just needed to manage the array of continued queries.

-Robert


-----Original Message-----
From: info-ingr...@kettleriverconsulting.com [mailto:info-ingr...@kettleriverconsulting.com] On Behalf Of Gerhard Hofmann
Sent: Wednesday, 11 August 2010 10:23 p.m.
To: info-...@kettleriverconsulting.com
Subject: Re: [Info-Ingres] IMA query duration

TIA
Gerhard
_______________________________________________
Info-Ingres mailing list
Info-...@kettleriverconsulting.com
http://ext-cando.kettleriverconsulting.com/mailman/listinfo/info-ingres

Roy Hann

unread,
Sep 14, 2010, 3:09:15 AM9/14/10
to
Robert Allely wrote:

> I originally raised this question, and then I coded some OpenROAD
> objects to do a similar thing to the ESQLC process mentioned below.
>
> The queries that have been there a while are stored in an array,
> they are written out to a table when its decided that they are slow

> number of seconds since first seen).
> If they are in LOCK state the blocking lock is found , using the
> usual ima method.
> It took a few hours to do but I already had all the ima sql setup,
> I just needed to manage the array of continued queries.

This is a useful and informative exercise, but if you need results and
development time is limited, you could also take a look at DBAnalyzer
from http://www.dmt.com for Ingres.

As well as shipping with a number of useful alarms and trend monitoring
tools, it also includes a performance database that you can query to
create your own alarms. The performance database is extremely useful
because it has already computed many of the rates/deltas you'd be
interested in.

--
Roy

UK Ingres User Association Conference 2011 will be on Tuesday June 7 2011.
Put the date in your diary today.


0 new messages