Logical Replication: SELECT pg_catalog.set_config Statement

[Hannes Kühtreiber]

Hello everybody,

not sure where to post this, general seems most appropriate.

We have tried logical replication in a test-setup, and it appears to 
work fine.

However, the following statement keeps running:

SELECT pg_catalog.set_config('search_path', '', false);

It is issued by the user 'subscriber' we have created for the subscription. 
Originally it only had the 'Replication' role, but we have subsequently made it 
Superuser.
However, the behaviour is the same.

  List of roles
 Role name  |   Attributes   | Member of
++---
 postgres   | Superuser, Create role, Create DB, Replication | {}
 subscriber | Superuser, Replication | {}

Strangely, when I log in as subscriber and query the searchpath, the result is 
'public'
I can then execute the above statement, and it sets the search_path to ''

At the next restart, the statement pops up again, and hangs 
Here is the log:
2021-05-17 16:08:03.595 CEST -usztestlogrepsub@10.139.0.41  
: LOG:  statement: SELECT 
pg_catalog.set_config('search_path', '', false);
2021-05-17 16:08:03.596 CEST -usztestlogrepsub@10.139.0.41  
: LOG:  received replication command: 
IDENTIFY_SYSTEM
2021-05-17 16:08:03.596 CEST -usztestlogrepsub@10.139.0.41  : 
LOG:  received replication command: START_REPLICATION SLOT "usztestlogrepsub" LOGICAL 
E51/EC041228 (proto_version '1', publication_names '"usztestlogreppub"')
2021-05-17 16:08:03.597 CEST -usztestlogrepsub@10.139.0.41  
: LOG:  starting logical decoding for slot 
"usztestlogrepsub"
2021-05-17 16:08:03.597 CEST -usztestlogrepsub@10.139.0.41  
: DETAIL:  Streaming transactions 
committing after E51/EC06B668, reading WAL from E51/EC06B668.
2021-05-17 16:08:03.597 CEST -usztestlogrepsub@10.139.0.41  
: LOG:  logical decoding found consistent 
point at E51/EC06B668
2021-05-17 16:08:03.597 CEST -usztestlogrepsub@10.139.0.41  
: DETAIL:  There are no running 
transactions.

Can anybody explain why this happens, and how to avoid it?

regards
Hannes


--

Re: Logical Replication: SELECT pg_catalog.set_config Statement

[Hannes Kühtreiber]

Hello Tom, thanks for your answer!


We found out because we are monitoring long running queries, and saw it 
had been running for a month before the restart yesterday.

I just queried pg_stat_activity and it seems to be running since then.

taimusz=# SELECT pid, query_start, usename, left(query,70)
FROM pg_stat_activity
WHERE query != '' AND query NOT ILIKE '%pg_stat_activity%'
ORDER BY query_start;
   pid   |  query_start  |  usename 
|  left

-+---++
 2321161 | 2021-05-17 16:15:13.906679+02 | subscriber | SELECT 
pg_catalog.set_config('search_path', '', false);


Am 18.05.2021 um 14:24 schrieb Tom Lane:

SELECT pg_catalog.set_config('search_path', '', false);
What makes you think it "keeps running"?  It looks to me like the
replication client does that and then goes about its business:
Admittedly, since you seem to have omitted the PID from your
log_line_prefix, it's hard to be 100% sure that these log entries
are from the same process.  But I bet they are.  The standard
walreceiver definitely does things this way.


Sorry for omitting the PIDs. But you are probably right, it is a test 
environment where not much is happening



In short, I think there's nothing to see here.

regards, tom lane


I wish this is the case. There seem to be no bloated tables, but before 
trying this on a production system I want to be sure


regards

Hannes

--

Re: Logical Replication: SELECT pg_catalog.set_config Statement appears to be hanging

[Hannes Kühtreiber]

Hello Tom,

thanks for the clarification. We are stumbling about this in psql (11.11)

I have now searched the release logs to find out when this will be resolved.

I found the following matching entry:

https://www.postgresql.org/docs/14/release-14.html  

E.1.3.1.7. System Views
.
Improve pg_stat_activity reporting of walsender processes (Tom Lane)
Previously only SQL commands were reported.

so we have to wait for psql14, or is there something else to this effect 
in an earlier release, that I failed to find?


regards

Hannes



Am 18.05.2021 um 15:15 schrieb Tom Lane:

=?UTF-8?Q?Hannes_K=c3=bchtreiber?=  writes:

Hello Tom, thanks for your answer!
We found out because we are monitoring long running queries, and saw it
had been running for a month before the restart yesterday.
I just queried pg_stat_activity and it seems to be running since then.

Oh, that's because pg_stat_activity continues to show the last plain-SQL
query executed by the session.

I think we recently changed things so that replication commands
would be shown in pg_stat_activity too, but evidently you're running
a version older than that.

regards, tom lane

Re: Logical Replication: SELECT pg_catalog.set_config Statement

[Hannes Kühtreiber]

Hello Jeremy,

thanks for your input (and sorry for the delay).

for our monitoring we query like this

SELECT EXTRACT(epoch FROM (LOCALTIMESTAMP - 
pg_stat_activity.query_start))::integer AS age

FROM pg_stat_activity
WHERE pg_stat_activity.state = 'active' AND query NOT LIKE 'autovacuum:%'
ORDER BY pg_stat_activity.query_start ASC
LIMIT 1

but we stumble over the query nontheless, its state being active

+-+-+
| Zustand | Laufende Abfrage    |
+-+-+
| active  | SELECT pg_catalog.set_config('search_path', '', false); |
+-+-+


is there another good way to exclude it?

regards

Hannes


Am 18.05.2021 um 17:52 schrieb Jeremy Smith:





We found out because we are monitoring long running queries, and
saw it had been running for a month before the restart yesterday.
I just queried pg_stat_activity and it seems to be running since
then.

taimusz=# SELECT pid, query_start, usename, left(query,70)
FROM pg_stat_activity
WHERE query != '' AND query NOT ILIKE '%pg_stat_activity%'
ORDER BY query_start;
   pid   |  query_start  |  usename
|  left

-+---++
 2321161 | 2021-05-17 16:15:13.906679+02 | subscriber | SELECT
pg_catalog.set_config('search_path', '', false);



You should add: AND state != 'idle' to filter out queries that are no 
longer running and don't have an open transaction.  Your query is 
finding long running sessions, not necessarily long running queries.

--