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.

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


On Jul 29, 2010, at 5:13 PM, Robert Allely 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...

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;
}


On Jul 30, 9:13*am, Robert Allely <Alle... (AT) poal (DOT) co.nz> wrote:

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

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

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.hofmann (AT) planat (DOT) de
------------------------------------------------------------------------
gerhard.hofmann (AT) planat (DOT) de's Profile: http://community.ingres.com/forum/member.php?userid=857
View this thread: http://community.ingres.com/forum/sh...ad.php?t=12397

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

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.hofmann (AT) planat (DOT) de
------------------------------------------------------------------------
gerhard.hofmann (AT) planat (DOT) de's Profile: http://community.ingres.com/forum/member.php?userid=857
View this thread: http://community.ingres.com/forum/sh...ad.php?t=12397

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

On 11 Aug., 11:57, Ingres Forums <info-
ing... (AT) kettleriverconsulting (DOT) com> wrote:
Unfortunately not here:
http://www.iua.org.uk/confindex.htm

Could you provide an alternative download link of the presentation?

TIA
Gerhard

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