[firebird-support] stale statements in MON$STATEMENTS

[Hamish Moffatt [e-mail] [firebird-support]]

Hi,

I'm trying to debug a concurrency issue I'm having with an application
of mine, connecting to Firebird 2.5.6, so I'm trying to understand the
various monitor tables. I have dozens of threads all making their own
connections to Firebird (superserver).

After running for a while my MON$STATEMENTS table shows over 100
statements with in state 0 (idle) with no transaction ID. They are
mostly "merge into ..." statements. I understand that the idle statement
means they have been prepared but not executed, but this shouldn't be
possible in my application source (prepare has never failed, and I
always execute).

Is there something else I must be doing wrong to cause these to hang around?

I also have a couple of plain selects in that table.




thanks,


Hamish

[Dimitry Sibiryakov [e-mail] [firebird-support]]

Post by Hamish Moffatt ***@risingsoftware.com [firebird-support]
I understand that the idle statement
means they have been prepared but not executed, but this shouldn't be
possible in my application source (prepare has never failed, and I
always execute).

Yes, but after execution they are idle again until unprepared or freed.
--
WBR, SD.


------------------------------------

------------------------------------

++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++

Visit http://www.firebirdsql.org and click the Documentation item
on the main (top) menu. Try FAQ and other links from the left-side menu there.

Also search the knowledgebases at http://www.ibphoenix.com/resources/documents/

++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
------------------------------------

Yahoo Groups Links

<*> To visit your group on the web, go to:
http://groups.yahoo.com/group/firebird-support/

<*> Your email settings:
Individual Email | Traditional

<*> To change settings online go to:
http://groups.yahoo.com/group/firebird-support/join
(Yahoo! ID required)

<*> To change settings via email:
firebird-support-***@yahoogroups.com
firebird-support-***@yahoogroups.com

<*> To unsubscribe from this group, send an email to:
firebird-support-***@yahoogroups.com

<*> Your use of Yahoo Groups is subject to:
https://info.yahoo.com/legal/us/yahoo/utos/terms/

[Hamish Moffatt [e-mail] [firebird-support]]

Post by Dimitry Sibiryakov ***@ibphoenix.com [firebird-support]

Post by Hamish Moffatt ***@risingsoftware.com [firebird-support]
I understand that the idle statement
means they have been prepared but not executed, but this shouldn't be
possible in my application source (prepare has never failed, and I
always execute).

Yes, but after execution they are idle again until unprepared or freed.

OK, thanks. I'm doing all my Firebird interaction with Qt and its IBASE
driver, so this should all be managed for me. It should free the
statements when they go out of scope.

It's a bit suspicious that 100 of these statements were the same one,
"merge into...", so I'll have to follow that up.

I also see a ton of connections on MON$ATTACHMENTS from the same thread
in my application (MON$REMOTE_PID, MON$REMOTE_ADDRESS both the same)
which also makes no sense.


Hamish



------------------------------------

------------------------------------

++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++

Visit http://www.firebirdsql.org and click the Documentation item
on the main (top) menu. Try FAQ and other links from the left-side menu there.

Also search the knowledgebases at http://www.ibphoenix.com/resources/documents/

++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
------------------------------------

Yahoo Groups Links

<*> To visit your group on the web, go to:
http://groups.yahoo.com/group/firebird-support/

<*> Your email settings:
Individual Email | Traditional

<*> To change settings online go to:
http://groups.yahoo.com/group/firebird-support/join
(Yahoo! ID required)

<*> To change settings via email:
firebird-support-***@yahoogroups.com
firebird-support-***@yahoogroups.com

<*> To unsubscribe from this group, send an email to:
firebird-support-***@yahoogroups.com

<*> Your use of Yahoo Groups is subject to:
https://info.yahoo.com/legal/us/yahoo/utos/terms/

['Thomas Steinmaurer' [e-mail] [firebird-support]]

Post by Hamish Moffatt ***@risingsoftware.com [firebird-support]

Post by Dimitry Sibiryakov ***@ibphoenix.com [firebird-support]

Post by Hamish Moffatt ***@risingsoftware.com [firebird-support]
I understand that the idle statement
means they have been prepared but not executed, but this shouldn't be
possible in my application source (prepare has never failed, and I
always execute).

Yes, but after execution they are idle again until unprepared or freed.

OK, thanks. I'm doing all my Firebird interaction with Qt and its IBASE
driver, so this should all be managed for me. It should free the
statements when they go out of scope.
It's a bit suspicious that 100 of these statements were the same one,
"merge into...", so I'll have to follow that up.
I also see a ton of connections on MON$ATTACHMENTS from the same thread
in my application (MON$REMOTE_PID, MON$REMOTE_ADDRESS both the same)
which also makes no sense.

Closing a connection implicitly will free the underlaying statements, thus due to your explanations, it seems you are leaking (not closing) connections.



--
With regards,
Thomas Steinmaurer
http://www.upscene.com

Professional Tools and Services for Firebird
FB TraceManager, IB LogManager, Database Health Check, Tuning etc.

[Hamish Moffatt [e-mail] [firebird-support]]

Post by 'Thomas Steinmaurer' ***@iblogmanager.com [firebird-support]

Post by Hamish Moffatt ***@risingsoftware.com [firebird-support]
I also see a ton of connections on MON$ATTACHMENTS from the same thread
in my application (MON$REMOTE_PID, MON$REMOTE_ADDRESS both the same)
which also makes no sense.

Closing a connection implicitly will free the underlaying statements,
thus due to your explanations, it seems you are leaking (not closing)
connections.

It looks like all the connections in MON$ATTACHMENTS have the
MON$REMOTE_PID set to the PID of my main thread, so this was a false
alarm. I (intend to) have one connection per thread, but I could have
100 threads.

I see mostly 1 idle statement per connections in MON$STATEMENTS,
occasionally 2. This must be a Qt driver thing, by design or by flaw I'm
not sure. I suppose it's harmless if they are idle and they are replaced
by the next statement, and destroyed when the connection is closed.

I'm also seeing idle transactions in MON$TRANSACTIONS sometimes. That is
presumably the cause of my big issue, which is that I am reading back
old data from the db.

Thanks, I keep digging.. and sorry this thread isn't making much sense.


Hamish

[Hamish Moffatt [e-mail] [firebird-support]]

Post by Hamish Moffatt ***@risingsoftware.com [firebird-support]
I'm also seeing idle transactions in MON$TRANSACTIONS sometimes. That
is presumably the cause of my big issue, which is that I am reading
back old data from the db.

OK, here's where I'm confused. The last statement executed by each
connection seems to stay listed, idle, in MON$STATEMENTS.

For each statement I execute, the database driver is doing

- isc_start_transaction
- isc_allocate_statement
- isc_prepare_statement
- isc_dsql_execute
- isc_commit_transaction
- isc_dsql_free_statement with DSQL_drop

Now I've enabled the fbtracemgr and what I see is that the FREE
STATEMENT does not happen until the next transaction is started. The
free_statement call causes a CLOSE_CURSOR event in the trace but the
FREE_STATEMENT does not come until the next transaction starts.

I've attached from two executes of "SELECT 1 FROM RDB$DATABASE". You can
hopefully see from the timestamps that the FREE_STATEMENT never starts
until just before the next START_TRANSACTION.

Anyway, is this all as expected? Maybe it's not even important.

What I am seeing is that a thread is getting old data from a SELECT,
suggesting that there's an active transaction/statement somewhere
keeping it pinned to old data. I should not have any such lingering
transactions/statements though.



thanks,


Hamish



----------

2016-12-03T16:30:40.9030 (12132:0279A674) TRACE_INIT
SESSION_4


2016-12-03T16:30:40.9040 (12132:0279A674) START_TRANSACTION
C:\DEV\WEBAPP_DEV\PROJECTS\SERVER\WEBAPP-SERVER\RISING5.FDB (ATT_886, SYSDBA:NONE, UTF8, TCPv4:127.0.0.1)
C:\dev\webapp_dev\projects\server\webapp-server\debug\webapp_server.exe:23260
(TRA_72718, CONCURRENCY | WAIT | READ_WRITE)

2016-12-03T16:30:51.8920 (12132:0279A674) PREPARE_STATEMENT
C:\DEV\WEBAPP_DEV\PROJECTS\SERVER\WEBAPP-SERVER\RISING5.FDB (ATT_886, SYSDBA:NONE, UTF8, TCPv4:127.0.0.1)
C:\dev\webapp_dev\projects\server\webapp-server\debug\webapp_server.exe:23260
(TRA_72718, CONCURRENCY | WAIT | READ_WRITE)

Statement 1130:
-------------------------------------------------------------------------------
SELECT 1 FROM RDB$DATABASE
0 ms

2016-12-03T16:30:51.8930 (12132:0279A674) EXECUTE_STATEMENT_START
C:\DEV\WEBAPP_DEV\PROJECTS\SERVER\WEBAPP-SERVER\RISING5.FDB (ATT_886, SYSDBA:NONE, UTF8, TCPv4:127.0.0.1)
C:\dev\webapp_dev\projects\server\webapp-server\debug\webapp_server.exe:23260
(TRA_72718, CONCURRENCY | WAIT | READ_WRITE)

Statement 1130:
-------------------------------------------------------------------------------
SELECT 1 FROM RDB$DATABASE

2016-12-03T16:30:51.8940 (12132:0279A674) COMMIT_TRANSACTION
C:\DEV\WEBAPP_DEV\PROJECTS\SERVER\WEBAPP-SERVER\RISING5.FDB (ATT_886, SYSDBA:NONE, UTF8, TCPv4:127.0.0.1)
C:\dev\webapp_dev\projects\server\webapp-server\debug\webapp_server.exe:23260
(TRA_72718, CONCURRENCY | WAIT | READ_WRITE)
1 ms, 1 write(s), 1 fetch(es), 1 mark(s)

2016-12-03T16:30:51.8940 (12132:0279A674) CLOSE_CURSOR
C:\DEV\WEBAPP_DEV\PROJECTS\SERVER\WEBAPP-SERVER\RISING5.FDB (ATT_886, SYSDBA:NONE, UTF8, TCPv4:127.0.0.1)
C:\dev\webapp_dev\projects\server\webapp-server\debug\webapp_server.exe:23260

Statement 1130:
-------------------------------------------------------------------------------
SELECT 1 FROM RDB$DATABASE

2016-12-03T16:32:01.7590 (12132:0279A674) FREE_STATEMENT
C:\DEV\WEBAPP_DEV\PROJECTS\SERVER\WEBAPP-SERVER\RISING5.FDB (ATT_886, SYSDBA:NONE, UTF8, TCPv4:127.0.0.1)
C:\dev\webapp_dev\projects\server\webapp-server\debug\webapp_server.exe:23260

Statement 1130:
-------------------------------------------------------------------------------
SELECT 1 FROM RDB$DATABASE

2016-12-03T16:32:01.7600 (12132:0279A674) START_TRANSACTION
C:\DEV\WEBAPP_DEV\PROJECTS\SERVER\WEBAPP-SERVER\RISING5.FDB (ATT_886, SYSDBA:NONE, UTF8, TCPv4:127.0.0.1)
C:\dev\webapp_dev\projects\server\webapp-server\debug\webapp_server.exe:23260
(TRA_72719, CONCURRENCY | WAIT | READ_WRITE)

2016-12-03T16:32:16.7560 (12132:0279A674) PREPARE_STATEMENT
C:\DEV\WEBAPP_DEV\PROJECTS\SERVER\WEBAPP-SERVER\RISING5.FDB (ATT_886, SYSDBA:NONE, UTF8, TCPv4:127.0.0.1)
C:\dev\webapp_dev\projects\server\webapp-server\debug\webapp_server.exe:23260
(TRA_72719, CONCURRENCY | WAIT | READ_WRITE)

Statement 1131:
-------------------------------------------------------------------------------
SELECT 1 FROM RDB$DATABASE
0 ms

2016-12-03T16:32:16.7560 (12132:0279A674) EXECUTE_STATEMENT_START
C:\DEV\WEBAPP_DEV\PROJECTS\SERVER\WEBAPP-SERVER\RISING5.FDB (ATT_886, SYSDBA:NONE, UTF8, TCPv4:127.0.0.1)
C:\dev\webapp_dev\projects\server\webapp-server\debug\webapp_server.exe:23260
(TRA_72719, CONCURRENCY | WAIT | READ_WRITE)

Statement 1131:
-------------------------------------------------------------------------------
SELECT 1 FROM RDB$DATABASE

2016-12-03T16:32:16.7580 (12132:0279A674) COMMIT_TRANSACTION
C:\DEV\WEBAPP_DEV\PROJECTS\SERVER\WEBAPP-SERVER\RISING5.FDB (ATT_886, SYSDBA:NONE, UTF8, TCPv4:127.0.0.1)
C:\dev\webapp_dev\projects\server\webapp-server\debug\webapp_server.exe:23260
(TRA_72719, CONCURRENCY | WAIT | READ_WRITE)
1 ms, 1 write(s), 1 fetch(es), 1 mark(s)

2016-12-03T16:32:16.7580 (12132:0279A674) CLOSE_CURSOR
C:\DEV\WEBAPP_DEV\PROJECTS\SERVER\WEBAPP-SERVER\RISING5.FDB (ATT_886, SYSDBA:NONE, UTF8, TCPv4:127.0.0.1)
C:\dev\webapp_dev\projects\server\webapp-server\debug\webapp_server.exe:23260

Statement 1131:
-------------------------------------------------------------------------------
SELECT 1 FROM RDB$DATABASE

2016-12-03T16:32:34.7380 (12132:0279A674) FREE_STATEMENT
C:\DEV\WEBAPP_DEV\PROJECTS\SERVER\WEBAPP-SERVER\RISING5.FDB (ATT_886, SYSDBA:NONE, UTF8, TCPv4:127.0.0.1)
C:\dev\webapp_dev\projects\server\webapp-server\debug\webapp_server.exe:23260

Statement 1131:
-------------------------------------------------------------------------------
SELECT 1 FROM RDB$DATABASE

2016-12-03T16:32:34.7390 (12132:0279A674) START_TRANSACTION
C:\DEV\WEBAPP_DEV\PROJECTS\SERVER\WEBAPP-SERVER\RISING5.FDB (ATT_886, SYSDBA:NONE, UTF8, TCPv4:127.0.0.1)
C:\dev\webapp_dev\projects\server\webapp-server\debug\webapp_server.exe:23260
(TRA_72720, CONCURRENCY | WAIT | READ_WRITE)

[Non-text portions of this message have been removed]