How long has a transaction or query been running?
Posted in 2025
Jacob Salomon asked how to tell how long a transaction or query has run, and about blocking checkpoints. Hedwig Fuchs and Art Kagel advised dbinfo('utc_to_datetime', starttime) on systxptab, joined to sysrstcb and sysconblock; columns named stamp are counters, not clock times. Andreas Legner questioned the checkpoint link. Jacob wanted to catch blocked checkpoints live.
Auto-generated by Claude from the posts below — may be imperfect; read the full thread.
Topics: Logging & Checkpoints, Jobs, Consulting & Announcements
Hi Family.
I've been quiet for too long so I'll make for that with two threads.
How to tell if there is blocking transaction at the moment. This will be the subject of my next thread.
How long has a transaction been running? And how long as a current query been running? That is the subject of this thread.
I see in the output of onstat -x stuff like this:
address flags userthread locks begin_logpos current logpos isol rb_time retrys coord
16f238028 A---- 16f1f0028 0 - - COMMIT - 0
16f238398 A---- 16f1f0918 0 - - COMMIT - 0
16f238708 A---- 16f1f1208 0 - - COMMIT - 0
1823e1788 A-B-- 7f0b80c98 4 2995248:0x8d71728 2995248:0x8d71760 DIRTY 00:00:00 0
1c6551f58 A-B-- c04336a98 34 2995244:0xc067018 2995248:0x141e5d0 DIRTY 00:03:53 0
I presume, subject to correction by y'all, that only the rows with info under begin_logpos and current_logpos are active transaction; I should be able to ignore al the other lines. And he estimated rb_time is a guess at how long it would take to roll back the transaction from the current point. Nothing about the length of time the transaction has been running. Going back to systrans: nada. AH, but systtrans is a view on systxptab. and there I find column stamp:
stamp integer, { activity time stamp }
Is that a count of seconds, an encoded datetime or an encoded interval, like days to seconds?
Of course, that would not necessarily lead me to a transaction that is causing a blocking checkpoint. But it might be a predictor.
Similarly,
onstat -g ses <sid>has no such timing information and neither do I see this in
onstat -g sql <sid>. How about view syssessions or better, its underlying tables. For example, I see .sysscblst:
connected integer, { time that user connected }
but again, I can't tell if this is a time stamp or number of seconds or an interval. The other table underlying the syssessions view, sysrstcb, sure has a lotta columns but non see to be time related.
(What table tells me the same stuff as
onstat -g sql
?)So I've done some research but come up almost empty. Unless someone tells me how interprets those integer columns.
Thanks much. Now to post the companion question, a lot simpler, I think.
------------------------------
+-----------------------------------------------------------+
| I am pleased to report that I had no problems today. |
| I had only issues, opportunities, challenges and valuable |
| learning experiences. |
+------------------------------------------ Jacob S --------+
------------------------------
Hi
try with something like
select dbinfo('utc_to_datetime', starttime) from systxptab
select dbinfo('utc_to_datetime', begintime) from systxptab
A rough estimate is in the message logfile: "begin_logpos between logpos of two checkpoints in this logical log
onlog output for the logical log has a BEGIN log record with a date at begin_logpos.
Regarding: And how long as a current query been running?
A query does not necessarily has an open transaction.
------------------------------
Hedwig Fuchs
------------------------------
Hi Jacob,
checkpoints being blocked, if that really is what's happening, is a concern, but it certainly is not a transaction per se, much less its duration, that can do this. You can have as many transactions open as you want, even for extended periods of time, and still get all kinds of checkpoints executed and completed.
So what makes you think a checkpoint is blocked?
Ahh, or is it about "block
ing
checkpoints"? That's even more independent from transactions
-> look at onstat -g ckp (or sysadmin:mon_checkpoint) -> trigger/caller of checkpoints marked as blocking.
Or is it, once again, about the blocking phase that every checkpoint, even a non-blocking one, has at its start?
BR,
Andreas
------------------------------
Andreas Legner
Informix Dev
HCL Software
------------------------------
Jacob: Any column in sysmaster named"*stamp*" or "*stmp*" is an internal "timestamp" which is just a counter of operations that just increases until it wraps. There is no direct association with any clock time. Real clock times are named "*time*" and are almost always Unix epochs which you can convert using DBINFO('utc_to_datetime', <value>) to a displayable DATETIME. For durations you can subtract one from another to get elapsed seconds. Hedwig pointed you in the right direction. You can join systxptab to sysrstcb on systxptab.owner = sysrstcb.address to get sid, pid, uid, etc. which will let you join to sysconblock (sid = sessionid) to get the statement and other details. Art ------------------------------ Art S. Kagel, President and Principal Consultant ASK Database Management Corp. www.askdbmgt.com ------------------------------
Andreas,
to forestall further speculation: I am asking about checkpoint that blocks everything. (On a separate note, I ran into a very specialized bug wherein a non-blocking checkpoint effectively blocks. But I'm not talking about that.) Here's what I'm talking about:
$ grep 'Block Time' $INFORMIXDIR/online.log|sed 's/,//'|awk '$10 >= 20.0 {print}'08/01/25 06:07:49 Checkpoint Statistics - Avg. Txn Block Time 54.815 # Txns blocked 100, Plog used 177384, Llog used 176260
08/06/25 06:15:47 Checkpoint Statistics - Avg. Txn Block Time 27.055 # Txns blocked 41, Plog used 128487, Llog used 88882
08/07/25 04:34:21 Checkpoint Statistics - Avg. Txn Block Time 45.637 # Txns blocked 72, Plog used 7675, Llog used 8186
08/07/25 09:03:05 Checkpoint Statistics - Avg. Txn Block Time 32.651 # Txns blocked 254, Plog used 237324, Llog used 109101
The above pipeline digs up situations where the server was blocked by a checkpoint for more that 20 seconds. But that is AFTER the fact. I want to catch it while it is happening (i.e.
onstat -
output says BLOCKED. Then jump into Hedwig's & Art's ideas to see who is running what query.
Hedwig &Art: Thanks for the pointers on those time stamps. I'll be practicing those queries a bit before I can incorporate then into a monitoring script.
------------------------------
+-----------------------------------------------------------+
| I am pleased to report that I had no problems today. |
| I had only issues, opportunities, challenges and valuable |
| learning experiences. |
+------------------------------------------ Jacob S --------+
------------------------------