Informix

Hi all. I'd like some assistance with the use of sql trace and dynamic explain.

When I encounter a long-running session, I try to use "onmode -Y [sessionid] 1 /tmp/filename.sessionid" to get some more detail. Sometimes that works for me, sometimes I get nothing. When I get no output, I can confirm that the session is ticking over statements, it's not idle. Just no output. 

If that fails, I move onto sql trace:
execute function task ("set sql tracing on session [sessid]","10000","2","med","user")
This turns it on for all sessions, not just the one I'm focusing on.

I do get the detail from sql trace, but sometimes it's like trying to sip from the fire hydrant, and other times I would prefer the explain output of onmode -Y. EXPLAIN_STATS is always on.

Regards
Jason


------------------------------
Jason Ball
------------------------------

#Informix

Onmode -Y will only capture SQL that is PREPARED after you issue the command and most well written applications PREPARE all of their SQL up front and just execute them over and over,  so there is nothing to capture.

Art

------------------------------
Art S. Kagel, President and Principal Consultant
ASK Database Management Corp.
www.askdbmgt.com
------------------------------

Original Message:
Sent: Tue August 31, 2021 04:22 AM
From: Jason Ball
Subject: Tracing single session

Hi all. I'd like some assistance with the use of sql trace and dynamic explain.

When I encounter a long-running session, I try to use "onmode -Y [sessionid] 1 /tmp/filename.sessionid" to get some more detail. Sometimes that works for me, sometimes I get nothing. When I get no output, I can confirm that the session is ticking over statements, it's not idle. Just no output. 

If that fails, I move onto sql trace:
execute function task ("set sql tracing on session [sessid]","10000","2","med","user")
This turns it on for all sessions, not just the one I'm focusing on.

I do get the detail from sql trace, but sometimes it's like trying to sip from the fire hydrant, and other times I would prefer the explain output of onmode -Y. EXPLAIN_STATS is always on.

Regards
Jason


------------------------------
Jason Ball
------------------------------

#Informix

As Art said, you'll only see the explain plan when a new statement is prepared.  For that reason a single long running SQL also won't show anything because it has already been optimized.  I seem to remember that there was an RFE requesting that using dynamic explain shows the explain plan of something already running...I am not sure.  But what I wanted to add is that you should still see the query statistics - expected rows/rows processed/etc - each time the session completes a query.  While not terribly useful on their own, if you can connect them to the queries that are running (a commonly repeated query in a loop for example), then you can capture the SQL and generate an explain plan for that query.  It's not great, but at least for simpler queries, it can give you an idea of what is going on.

If you are not seeing the query statistics while the session is continuing to process additional statements, then I don't know why that would be.


------------------------------
Mike Walker
xDB Systems, Inc
www.xdbsystems.com
------------------------------

Original Message:
Sent: Tue August 31, 2021 04:22 AM
From: Jason Ball
Subject: Tracing single session

Hi all. I'd like some assistance with the use of sql trace and dynamic explain.

When I encounter a long-running session, I try to use "onmode -Y [sessionid] 1 /tmp/filename.sessionid" to get some more detail. Sometimes that works for me, sometimes I get nothing. When I get no output, I can confirm that the session is ticking over statements, it's not idle. Just no output. 

If that fails, I move onto sql trace:
execute function task ("set sql tracing on session [sessid]","10000","2","med","user")
This turns it on for all sessions, not just the one I'm focusing on.

I do get the detail from sql trace, but sometimes it's like trying to sip from the fire hydrant, and other times I would prefer the explain output of onmode -Y. EXPLAIN_STATS is always on.

Regards
Jason


------------------------------
Jason Ball
------------------------------

#Informix

Oh, forgot, I think the API function you used to turn tracing on for that one session was not correct. It should be:

execute function task( "set sql tracing session", "on", <session id> );

You would set the other parameters like number of SQL trace buffers, buffer size, and trace level separately with:
execute function task( "set sql tracing on", <#traces>, <buffer size>, <level>, "user" ); 
Where <level> is "low", "medium", or "high".

------------------------------
Art S. Kagel, President and Principal Consultant
ASK Database Management Corp.
www.askdbmgt.com
------------------------------

Original Message:
Sent: Tue August 31, 2021 07:43 AM
From: Mike Walker
Subject: Tracing single session

As Art said, you'll only see the explain plan when a new statement is prepared.  For that reason a single long running SQL also won't show anything because it has already been optimized.  I seem to remember that there was an RFE requesting that using dynamic explain shows the explain plan of something already running...I am not sure.  But what I wanted to add is that you should still see the query statistics - expected rows/rows processed/etc - each time the session completes a query.  While not terribly useful on their own, if you can connect them to the queries that are running (a commonly repeated query in a loop for example), then you can capture the SQL and generate an explain plan for that query.  It's not great, but at least for simpler queries, it can give you an idea of what is going on.

If you are not seeing the query statistics while the session is continuing to process additional statements, then I don't know why that would be.


------------------------------
Mike Walker
xDB Systems, Inc
www.xdbsystems.com

Original Message:
Sent: Tue August 31, 2021 04:22 AM
From: Jason Ball
Subject: Tracing single session

Hi all. I'd like some assistance with the use of sql trace and dynamic explain.

When I encounter a long-running session, I try to use "onmode -Y [sessionid] 1 /tmp/filename.sessionid" to get some more detail. Sometimes that works for me, sometimes I get nothing. When I get no output, I can confirm that the session is ticking over statements, it's not idle. Just no output. 

If that fails, I move onto sql trace:
execute function task ("set sql tracing on session [sessid]","10000","2","med","user")
This turns it on for all sessions, not just the one I'm focusing on.

I do get the detail from sql trace, but sometimes it's like trying to sip from the fire hydrant, and other times I would prefer the explain output of onmode -Y. EXPLAIN_STATS is always on.

Regards
Jason


------------------------------
Jason Ball
------------------------------

#Informix

Thanks Art and Mike!

The comment "most well written applications PREPARE all of their SQL up front" might explain the variable success I've had with the command in the past.

Mike, I will try running onmode -Y with argument 2 to see if that gets me the query statistics.

And thanks Art for pointing out the command error. 

Appreciate the help!



------------------------------
Jason Ball
------------------------------

Original Message:
Sent: Tue August 31, 2021 08:19 AM
From: Art Kagel
Subject: Tracing single session

Oh, forgot, I think the API function you used to turn tracing on for that one session was not correct. It should be:

execute function task( "set sql tracing session", "on", <session id> );

You would set the other parameters like number of SQL trace buffers, buffer size, and trace level separately with:
execute function task( "set sql tracing on", <#traces>, <buffer size>, <level>, "user" ); 
Where <level> is "low", "medium", or "high".

------------------------------
Art S. Kagel, President and Principal Consultant
ASK Database Management Corp.
www.askdbmgt.com

Original Message:
Sent: Tue August 31, 2021 07:43 AM
From: Mike Walker
Subject: Tracing single session

As Art said, you'll only see the explain plan when a new statement is prepared.  For that reason a single long running SQL also won't show anything because it has already been optimized.  I seem to remember that there was an RFE requesting that using dynamic explain shows the explain plan of something already running...I am not sure.  But what I wanted to add is that you should still see the query statistics - expected rows/rows processed/etc - each time the session completes a query.  While not terribly useful on their own, if you can connect them to the queries that are running (a commonly repeated query in a loop for example), then you can capture the SQL and generate an explain plan for that query.  It's not great, but at least for simpler queries, it can give you an idea of what is going on.

If you are not seeing the query statistics while the session is continuing to process additional statements, then I don't know why that would be.


------------------------------
Mike Walker
xDB Systems, Inc
www.xdbsystems.com

Original Message:
Sent: Tue August 31, 2021 04:22 AM
From: Jason Ball
Subject: Tracing single session

Hi all. I'd like some assistance with the use of sql trace and dynamic explain.

When I encounter a long-running session, I try to use "onmode -Y [sessionid] 1 /tmp/filename.sessionid" to get some more detail. Sometimes that works for me, sometimes I get nothing. When I get no output, I can confirm that the session is ticking over statements, it's not idle. Just no output. 

If that fails, I move onto sql trace:
execute function task ("set sql tracing on session [sessid]","10000","2","med","user")
This turns it on for all sessions, not just the one I'm focusing on.

I do get the detail from sql trace, but sometimes it's like trying to sip from the fire hydrant, and other times I would prefer the explain output of onmode -Y. EXPLAIN_STATS is always on.

Regards
Jason


------------------------------
Jason Ball
------------------------------

#Informix

The argument of "1" is supposed to show the query plan AND query statistics, and "2" is the query plan only.

-Y <sid> <0|1|2> [filename] Set or unset dynamic explain
0=off 1=plan + statistics on 2=only plan on


------------------------------
Mike Walker
xDB Systems, Inc
www.xdbsystems.com
------------------------------

Original Message:
Sent: Tue August 31, 2021 07:37 PM
From: Jason Ball
Subject: Tracing single session

Thanks Art and Mike!

The comment "most well written applications PREPARE all of their SQL up front" might explain the variable success I've had with the command in the past.

Mike, I will try running onmode -Y with argument 2 to see if that gets me the query statistics.

And thanks Art for pointing out the command error. 

Appreciate the help!



------------------------------
Jason Ball

Original Message:
Sent: Tue August 31, 2021 08:19 AM
From: Art Kagel
Subject: Tracing single session

Oh, forgot, I think the API function you used to turn tracing on for that one session was not correct. It should be:

execute function task( "set sql tracing session", "on", <session id> );

You would set the other parameters like number of SQL trace buffers, buffer size, and trace level separately with:
execute function task( "set sql tracing on", <#traces>, <buffer size>, <level>, "user" ); 
Where <level> is "low", "medium", or "high".

------------------------------
Art S. Kagel, President and Principal Consultant
ASK Database Management Corp.
www.askdbmgt.com

Original Message:
Sent: Tue August 31, 2021 07:43 AM
From: Mike Walker
Subject: Tracing single session

As Art said, you'll only see the explain plan when a new statement is prepared.  For that reason a single long running SQL also won't show anything because it has already been optimized.  I seem to remember that there was an RFE requesting that using dynamic explain shows the explain plan of something already running...I am not sure.  But what I wanted to add is that you should still see the query statistics - expected rows/rows processed/etc - each time the session completes a query.  While not terribly useful on their own, if you can connect them to the queries that are running (a commonly repeated query in a loop for example), then you can capture the SQL and generate an explain plan for that query.  It's not great, but at least for simpler queries, it can give you an idea of what is going on.

If you are not seeing the query statistics while the session is continuing to process additional statements, then I don't know why that would be.


------------------------------
Mike Walker
xDB Systems, Inc
www.xdbsystems.com

Original Message:
Sent: Tue August 31, 2021 04:22 AM
From: Jason Ball
Subject: Tracing single session

Hi all. I'd like some assistance with the use of sql trace and dynamic explain.

When I encounter a long-running session, I try to use "onmode -Y [sessionid] 1 /tmp/filename.sessionid" to get some more detail. Sometimes that works for me, sometimes I get nothing. When I get no output, I can confirm that the session is ticking over statements, it's not idle. Just no output. 

If that fails, I move onto sql trace:
execute function task ("set sql tracing on session [sessid]","10000","2","med","user")
This turns it on for all sessions, not just the one I'm focusing on.

I do get the detail from sql trace, but sometimes it's like trying to sip from the fire hydrant, and other times I would prefer the explain output of onmode -Y. EXPLAIN_STATS is always on.

Regards
Jason


------------------------------
Jason Ball
------------------------------

#Informix

Hello Jason,

If onmode -Y or task('onmode', 'Y', ..... ) does not produce any output (more precisely no file) it can also be due to error IT31262. If you execute the command several times with different filenames, Informix uses the 1st filename also for later calls with other sessions. The safest way is to check in the online.log after the onmode which file is used.

There you will find, if it uses the file for the first time, a line like this:

Explain file for session <sessionid>: /tmp/sqlexplain.out


Andreas

------------------------------
Andreas Seifert
CURSOR Software AG
http://www.admin-scout.com
------------------------------

Original Message:
Sent: Tue August 31, 2021 04:22 AM
From: Jason Ball
Subject: Tracing single session

Hi all. I'd like some assistance with the use of sql trace and dynamic explain.

When I encounter a long-running session, I try to use "onmode -Y [sessionid] 1 /tmp/filename.sessionid" to get some more detail. Sometimes that works for me, sometimes I get nothing. When I get no output, I can confirm that the session is ticking over statements, it's not idle. Just no output. 

If that fails, I move onto sql trace:
execute function task ("set sql tracing on session [sessid]","10000","2","med","user")
This turns it on for all sessions, not just the one I'm focusing on.

I do get the detail from sql trace, but sometimes it's like trying to sip from the fire hydrant, and other times I would prefer the explain output of onmode -Y. EXPLAIN_STATS is always on.

Regards
Jason


------------------------------
Jason Ball
------------------------------

#Informix