Обсуждение: How to get cursor query
I have a long executing query via foreign data wrapper and on the remote server i can see that the query is fetching data from the cursor
=# select application_name, state, query from pg_stat_activity where pid = 15455;
application_name │ state │ query
──────────────────┼────────┼─────────────────────
postgres_fdw │ active │ FETCH 100 FROM c514Is it possible to get query text corresponding to cursor c514?
One of the solution is to turn statement logging on (found it here http://www.postgresql.org/message-id/1361CEF686657C41A139AD8C3145632B44B33A8F@E2010-MB1.manord.com), but it works if i turn statement logging on before query execution. What can i do in case of connection to the server after the statement was executed?
On 08/18/2015 01:43 AM, Mikhail wrote: > Hi, > I have a long executing query via foreign data wrapper and on the remote > server i can see that the query is fetching data from the cursor > > =# select application_name, state, query from pg_stat_activity where pid > = 15455; > application_name │ state │ query > ──────────────────┼────────┼───────────────────── > postgres_fdw │ active │ FETCH 100 FROM c514 > > Is it possible to get query text corresponding to cursor c514? > > One of the solution is to turn statement logging on (found it here > http://www.postgresql.org/message-id/1361CEF686657C41A139AD8C3145632B44B33A8F@E2010-MB1.manord.com), > but it works if i turn statement logging on before query execution. What > can i do in case of connection to the server after the statement was > executed? The only thing I can think to do is load pg_stat_statements: http://www.postgresql.org/docs/9.4/interactive/pgstatstatements.html -- Adrian Klaver adrian.klaver@aklaver.com
Adrian Klaver <adrian.klaver@aklaver.com> writes: > On 08/18/2015 01:43 AM, Mikhail wrote: >> I have a long executing query via foreign data wrapper and on the remote >> server i can see that the query is fetching data from the cursor >> ... >> Is it possible to get query text corresponding to cursor c514? > The only thing I can think to do is load pg_stat_statements: > http://www.postgresql.org/docs/9.4/interactive/pgstatstatements.html That won't help after-the-fact either. If you're using postgres_fdw then the set of queries it could issue via a cursor is pretty restricted --- just SELECT-from-single-table AFAIR --- and you could tell which table by looking at the locks held by the cursor transaction (see pg_locks on the remote server). Perhaps that's close enough? regards, tom lane
On 08/18/2015 06:44 AM, Tom Lane wrote: > Adrian Klaver <adrian.klaver@aklaver.com> writes: >> On 08/18/2015 01:43 AM, Mikhail wrote: >>> I have a long executing query via foreign data wrapper and on the remote >>> server i can see that the query is fetching data from the cursor >>> ... >>> Is it possible to get query text corresponding to cursor c514? > >> The only thing I can think to do is load pg_stat_statements: >> http://www.postgresql.org/docs/9.4/interactive/pgstatstatements.html > > That won't help after-the-fact either. Well at some point the query will leave the view, but by default pg_stat_statements tracks the last 5000 distinct statements, so you have some time > 0 to find it. > > If you're using postgres_fdw then the set of queries it could issue via a > cursor is pretty restricted --- just SELECT-from-single-table AFAIR --- > and you could tell which table by looking at the locks held by the cursor > transaction (see pg_locks on the remote server). Perhaps that's close > enough? > > regards, tom lane > -- Adrian Klaver adrian.klaver@aklaver.com
Adrian Klaver <adrian.klaver@aklaver.com> writes: > On 08/18/2015 06:44 AM, Tom Lane wrote: >> Adrian Klaver <adrian.klaver@aklaver.com> writes: >>> The only thing I can think to do is load pg_stat_statements: >>> http://www.postgresql.org/docs/9.4/interactive/pgstatstatements.html >> That won't help after-the-fact either. > Well at some point the query will leave the view, but by default > pg_stat_statements tracks the last 5000 distinct statements, so you have > some time > 0 to find it. No, you don't have any time to find it, because pg_stat_statements can only track operations in backends that it's already been loaded into. What's more, it requires shared memory that can only be allocated at postmaster start, so that there's really no way to load it without a postmaster restart. regards, tom lane
On 08/18/2015 07:11 AM, Tom Lane wrote: > Adrian Klaver <adrian.klaver@aklaver.com> writes: >> On 08/18/2015 06:44 AM, Tom Lane wrote: >>> Adrian Klaver <adrian.klaver@aklaver.com> writes: >>>> The only thing I can think to do is load pg_stat_statements: >>>> http://www.postgresql.org/docs/9.4/interactive/pgstatstatements.html > >>> That won't help after-the-fact either. > >> Well at some point the query will leave the view, but by default >> pg_stat_statements tracks the last 5000 distinct statements, so you have >> some time > 0 to find it. > > No, you don't have any time to find it, because pg_stat_statements can > only track operations in backends that it's already been loaded into. I was not clear enough. The intent was for the OP to load pg_stat_statements into the remote server and just leave it running. At that point you have something that replicates(to a degree) log_statement = 'all' in postgresql.conf without having to remember to turn it on or off. It imposes an overhead, but that is the case for anything that tracks history. It up to the user to decide whether the benefit is worth the cost. > What's more, it requires shared memory that can only be allocated at > postmaster start, so that there's really no way to load it without a > postmaster restart. > > regards, tom lane > -- Adrian Klaver adrian.klaver@aklaver.com
I'm running supposedly an easy operation - renaming index and my session hangs on it. pg_stat_activity shows that process is active and is waiting for lock:
=# select application_name, waiting, state, query from pg_stat_activity where pid = 15179;
application_name │ waiting │ state │ query
─────────────────┼─────────┼────────┼─────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────
psql │ t │ active │ ALTER INDEX ebsm.fki_eb_order_details_acquiring_order_details_guid RENAME TO idx_tst;locks for that database:
=# select locktype, relation, c.relname, virtualtransaction, pid, mode, granted, fastpath,
(SELECT MIN(l1.pid)
FROM pg_locks l1
WHERE GRANTED
AND (relation IN (SELECT relation FROM pg_locks l2 WHERE l2.pid = l.pid AND NOT granted)
OR
transactionid IN (SELECT transactionid FROM pg_locks l3 WHERE l3.pid = l.pid AND NOT granted))) AS blockedby
from pg_locks l
JOIN pg_class c ON c.oid = l.relation
where l.database in (select oid from pg_database where datname = 'mytstdb');
locktype ¦ relation ¦ relname ¦ virtualtransaction ¦ pid ¦ mode ¦ granted ¦ fastpath ¦ blockedby
---------+----------+---------------------------------------------------+--------------------+-------+---------------------+---------+----------+----------
relation ¦ 3455 ¦ pg_class_tblspc_relfilenode_index ¦ 3/482 ¦ 24388 ¦ AccessShareLock ¦ t ¦ t ¦ NULL
relation ¦ 2663 ¦ pg_class_relname_nsp_index ¦ 3/482 ¦ 24388 ¦ AccessShareLock ¦ t ¦ t ¦ NULL
relation ¦ 2662 ¦ pg_class_oid_index ¦ 3/482 ¦ 24388 ¦ AccessShareLock ¦ t ¦ t ¦ NULL
relation ¦ 1259 ¦ pg_class ¦ 3/482 ¦ 24388 ¦ AccessShareLock ¦ t ¦ t ¦ NULL
relation ¦ 11187 ¦ pg_locks ¦ 3/482 ¦ 24388 ¦ AccessShareLock ¦ t ¦ t ¦ NULL
relation ¦ 28686 ¦ eb_order_details ¦ -1/222236974 ¦ NULL ¦ AccessShareLock ¦ t ¦ f ¦ NULL
relation ¦ 28756 ¦ fki_eb_order_details_acquiring_order_details_guid ¦ -1/222236974 ¦ NULL ¦ AccessShareLock ¦ t ¦ f ¦ NULL
relation ¦ 28689 ¦ pk_eb_order_details ¦ -1/222236974 ¦ NULL ¦ AccessShareLock ¦ t ¦ f ¦ NULL
relation ¦ 28756 ¦ fki_eb_order_details_acquiring_order_details_guid ¦ 11/2284 ¦ 15179 ¦ AccessExclusiveLock ¦ f ¦ f ¦ NULL
(9 rows)So, it seems like no other sessions blocks my session. (If it makes sense, the fields page, tuple, virtualxid, transactionid, classid, objid, objsubid have NULL values).
There is no activity on cpu/hdd and even no activity inside process
# strace -p 15179
Process 15179 attached - interrupt to quit
recvfrom(9, "Q\0\0\0\200ALTER INDEX ebsm.fki_eb_ord"..., 8192, 0, NULL, NULL) = 129
setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={1, 0}}, NULL) = 0
semop(16973888, {{2, -1, 0}}, 1) = -1 EINTR (Interrupted system call)
--- SIGALRM (Alarm clock) @ 0 (0) ---
rt_sigreturn(0x1c4f7260806a7) = -1 EINTR (Interrupted system call)
semop(16973888, {{2, -1, 0}}, 1and no further action within hours. Perf and top shows the same: no action performing by process.
The situation is reproducible: i can interrupt the process, run index renaming again and i'll get the same situation, described above.
Is there any ideas what is happening inside the database?
Regards, Mikhail