[pgpool-general: 7219] Re: Idle connection in database
Nikhil Shetty
nikhil.dba04 at gmail.com
Sun Aug 30 14:24:00 JST 2020
Hi Tatsuo,
I have to reopen this issue because after a lot of debugging and reading
documentation on connection_life_time though there is not much of it, this
parameter doesn't work as it should.
First I want to be correct in my understanding that this parameter
terminates cached backend connections in the database.So, I test a simple
scenario as follows:
PGPOOL - 128.199.224.132
*Parameters set for pooling*
serialize_accept=on
child_life_time=0
child_max_connections=0
client_idle_limit=0
connection_life_time=10
*I am running a mixed.sql file which contain below statements*
BEGIN;
SELECT CURRENT_TIMESTAMP;
INSERT into t1 values(3);
INSERT into t1 values(4);
select pg_sleep(5);
INSERT into t1 values(5);
UPDATE t1 set id=4 where id=5;
END;
After executing some inserts it will sleep for 5 seconds and then execute
one update and an insert before closing the connection.
*1) Status of nodes*
-bash-4.2$ psql -h 128.199.224.132 -p 9999 -U enterprisedb
psql.bin (11.6.13)
Type "help" for help.
edb=# show pool_nodes;
node_id | hostname | port | status | lb_weight | role |
select_cnt | load_balance_node | replication_delay | replication_state |
replication_syn
c_state | last_status_change
---------+-----------------+------+--------+-----------+---------+------------+-------------------+-------------------+-------------------+----------------
--------+---------------------
0 | 128.199.222.92 | 5445 | up | 0.000000 | primary | 0
| false | 0 | |
| 2020-08-30 04:58:24
1 | 128.199.222.124 | 5445 | up | 1.000000 | standby | 0
| true | 0 | |
| 2020-08-30 04:58:24
(2 rows)
*2) Running the mixed.sql file*
-bash-4.2$ psql -h 128.199.224.132 -p 9999 -U enterprisedb -f mixed.sql
BEGIN
current_timestamp
----------------------------------
30-AUG-20 10:31:47.396527 +05:30
(1 row)
INSERT 0 1
INSERT 0 1
pg_sleep
----------
(1 row)
INSERT 0 1
UPDATE 1
COMMIT
-bash-4.2$
*3) pool_pools output shows pgpool (pid - 31560) created one connection to
master(pid - 31550) and one to standby (pid - 28954) *
edb=# show pool_pools;
pool_pid | start_time | pool_id | backend_id | database |
username | create_time | majorversion | minorversion |
pool_counter | pool_
backendpid | pool_connected
----------+---------------------+---------+------------+----------+--------------+---------------------+--------------+--------------+--------------+------
-----------+----------------
31560 | 2020-08-30 04:51:54 | 0 | 0 | edb |
enterprisedb | 2020-08-30 05:01:47 | 3 | 0 | 1
| 31550
| 0
31560 | 2020-08-30 04:51:54 | 0 | 1 | edb |
enterprisedb | 2020-08-30 05:01:47 | 3 | 0 | 1
| 28954
| 0
*4) Status of process id 31550 on master.After the run, as seen below on
the database is idle*
-bash-4.2$ ps -ef |grep 224.132
enterpr+ 31550 9148 0 05:01 ? 00:00:00 postgres: enterprisedb edb
128.199.224.132[49656] idle
*5) Status of processid 31560 on pgpool.* *After the run, as seen below
pgpool has released connection as soon as transaction completes*
[root at pgpool-p pgpool4.1]# ps -ef |grep 31560
enterpr+ 31560 31557 0 04:51 ? 00:00:00 pgpool: wait for accept lock
*6) After 10 seconds, this cached connection on database should have been
terminated as per my understanding of connection_life_time parameter but as
seen below it has not terminated*
edb=# select * from pg_stat_activity where client_addr ='128.199.224.132';
-[ RECORD 1 ]----+---------------------------------
datid | 67127
datname | edb
pid | 31550
usesysid | 10
usename | enterprisedb
application_name | psql.bin
client_addr | 128.199.224.132
client_hostname |
client_port | 49656
backend_start | 30-AUG-20 10:31:47.380345 +05:30
xact_start |
query_start | 30-AUG-20 10:31:52.411607 +05:30
state_change | 30-AUG-20 10:31:52.411714 +05:30
wait_event_type | Client
wait_event | ClientRead
state | idle
backend_xid |
backend_xmin |
query | DISCARD ALL
backend_type | client backend
Do not mind the timestamp, it is in IST for the above query.
*7) From the pgpool logs, it sets the alarm after 10 sec but doesn't really
close the connection after 10 seconds*
Aug 30 05:01:52 Pgpool-p pgpool[*31560*]: [252-2] 2020-08-30 05:01:52: pid
31560: DETAIL: setting alarm after 10 seconds
Attaching pgpool logs as well.
On Wed, Aug 12, 2020 at 9:02 PM Nikhil Shetty <nikhil.dba04 at gmail.com>
wrote:
> Hi Tatsuo,
>
> Thank you, I will check how this works.
>
>
> On Tue, Aug 11, 2020 at 5:52 PM Tatsuo Ishii <ishii at sraoss.co.jp> wrote:
>
>> Hi Nikhil,
>>
>> > Hi Tatsuo,
>> >
>> > We are checking the patch internally before we go ahead and deploy in
>> > production.
>>
>> Ok.
>>
>> > If I want to set only one of either connection_life_time or
>> > client_idle_limit. What do you recommend? Should I set
>> > client_idle_limit=120 and connection_life_time=0, do you foresee any
>> > effects of these settings for connection pooling?
>>
>> In general connection_life_time is better because:
>>
>> 1. when client_idle_limit expires, pgpool needs to fork a new process,
>> but connection_life_time does not.
>>
>> 2. when client_idle_limit expires, it looses mutiple connection pools
>> (this only applicatable fro max_pool > 1 case) because the
>> connection pools the process hold go away.
>>
>> However if you have very short and frequent sessions, more alarm
>> system calls with connection_life_time are required and maybe
>> client_idle_limit wins in this case.
>>
>> > Thank you for your time and support.
>> >
>> > Thanks and Regards,
>> > Nikhil
>> >
>> > On Mon, Aug 10, 2020 at 11:58 AM Tatsuo Ishii <ishii at sraoss.co.jp>
>> wrote:
>> >
>> >> Hi Nikhil,
>> >>
>> >> I have been investigating if there's any case when
>> >> connection_life_time is not working. Actually it *is*. If primary node
>> >> is not node 0, connection_life_time does not work. Attached is the
>> >> patch to fix that. Please try, if you like.
>> >>
>> >> > According to your previous message, corresponding pgpool process was
>> >> > not there, but PostgreSQL backend process were still running. I
>> >> > suspect the backend process was waiting for TCP/IP connection was
>> >> > terminated. But to know what was actually happening, I was waiting
>> for
>> >> > your response.
>> >> >
>> >> >>> "DISCARD ALL" and state idle. I will have to test again to check
>> the
>> >> socket
>> >> >>> status of pid.I will get back on this
>> >> >
>> >> > What was that?
>> >> >
>> >> >> Hi Tatsuo,
>> >> >>
>> >> >>
>> >> >> Ant reason why connection_idle_limit doesn't remove backend
>> connection
>> >> >> after time limit is crossed
>> >> >>
>> >> >> Thanks and Regards,
>> >> >> Nikhil
>> >> >>
>> >> >> On Sun, Aug 2, 2020, 12:48 Nikhil Shetty <nikhil.dba04 at gmail.com>
>> >> wrote:
>> >> >>
>> >> >>> Hi Tatsuo,
>> >> >>>
>> >> >>> I want to correct my statement from previous email:
>> >> >>>
>> >> >>> From ps status *I could not see *that the process (18190 and 18193)
>> >> were
>> >> >>> still present on pgpool but the backend process was still present
>> with
>> >> >>> "DISCARD ALL" and state idle. I will have to test again to check
>> the
>> >> socket
>> >> >>> status of pid.I will get back on this
>> >> >>>
>> >> >>> On Sun, Aug 2, 2020 at 12:15 PM Nikhil Shetty <
>> nikhil.dba04 at gmail.com>
>> >> >>> wrote:
>> >> >>>
>> >> >>>> Hi Tatsuo,
>> >> >>>>
>> >> >>>> >> Assuming you executed "show pool_pools" long after 2020-08-01
>> >> >>>> >> 06:21:26, that is very strange because connection_life_time
>> should
>> >> >>>> >> have been already expired. I wonder if pgpool tried to
>> disconnect
>> >> the
>> >> >>>> >> connection but failed. To check what actually happend, can you
>> >> check
>> >> >>>> >> ps status of pgpool process 18190 and 18193?
>> >> >>>>
>> >> >>>> >> Also it would be nice you can examine the socket status of
>> >> PostgreSQL
>> >> >>>> >> backend 29321 and 29619, and pgpool socket status of process
>> 18190
>> >> and
>> >> >>>> >> 18193?
>> >> >>>>
>> >> >>>> From ps status I could see that the process (18190 and 18193) were
>> >> still
>> >> >>>> present on pgpool. I will have to test again to check the socket
>> >> status of
>> >> >>>> pid.I will get back on this
>> >> >>>>
>> >> >>>> Meanwhile, I did some testing of my own for these two parameters(
>> >> >>>> client_idle_limit and connection_life_time ) and their behaviour:
>> >> >>>>
>> >> >>>>
>> >> >>>> *Test:*
>> >> >>>>
>> >> >>>> Database IP:128.199.222.92(master)
>> >> >>>> Pgpool IP: 128.199.224.132
>> >> >>>>
>> >> >>>> *Scenario1:*
>> >> >>>>
>> >> >>>> max_pool=1
>> >> >>>> num_init_children=100
>> >> >>>> serialize_accept=on
>> >> >>>> child_max_connections=0
>> >> >>>> child_life_time=0
>> >> >>>> connection_life_time=60
>> >> >>>> client_idle_limit=0
>> >> >>>>
>> >> >>>> *1. Connected to Pgpool and ran a query with \watch 1:*
>> >> >>>> select count(*) from pgbench_accounts ;
>> >> >>>> \watch 1
>> >> >>>> Sat 01 Aug 2020 07:25:54 AM UTC (every 1s)
>> >> >>>>
>> >> >>>> count
>> >> >>>> ---------
>> >> >>>> 6000000
>> >> >>>>
>> >> >>>> *2. Checking session in database, one session is active from
>> pgpool*
>> >> >>>> Sat 01 Aug 2020 07:26:14 AM UTC
>> (every 1s)
>> >> >>>>
>> >> >>>> pid | query | usename |
>> >> >>>> client_addr | count | state
>> >> >>>>
>> >> >>>>
>> >>
>> ------+-----------------------------------------+--------------+-----------------+-------+--------
>> >> >>>> 3420 | select count(*) from pgbench_accounts ; | enterprisedb |
>> >> >>>> 128.199.224.132 | 1 | active
>> >> >>>> (1 row)
>> >> >>>>
>> >> >>>> *3. Stopped the query after sometime using Ctrl-C but session is
>> still
>> >> >>>> open*
>> >> >>>> Sat 01 Aug 2020 07:27:35 AM UTC (every 1s)
>> >> >>>>
>> >> >>>> count
>> >> >>>> ---------
>> >> >>>> 6000000
>> >> >>>> (1 row)
>> >> >>>>
>> >> >>>> ^Cedb=#
>> >> >>>> edb=#
>> >> >>>>
>> >> >>>> *4. Checking session in database, state is now idle*
>> >> >>>>
>> >> >>>> Sat 01 Aug 2020 07:28:14 AM UTC (every
>> 1s)
>> >> >>>>
>> >> >>>> pid | query | usename |
>> >> >>>> client_addr | count | state
>> >> >>>>
>> >> >>>>
>> >>
>> ------+-----------------------------------------+--------------+-----------------+-------+-------
>> >> >>>> 3420 | select count(*) from pgbench_accounts ; | enterprisedb |
>> >> >>>> 128.199.224.132 | 1 | idle
>> >> >>>>
>> >> >>>>
>> >> >>>> *5. Checking session in database after 2 minutes, I can still see
>> the
>> >> >>>> database session idle*
>> >> >>>>
>> >> >>>> Sat 01 Aug 2020 07:30:02 AM UTC (every
>> 1s)
>> >> >>>>
>> >> >>>> pid | query | usename |
>> >> >>>> client_addr | count | state
>> >> >>>>
>> >> >>>>
>> >>
>> ------+-----------------------------------------+--------------+-----------------+-------+-------
>> >> >>>> 3420 | select count(*) from pgbench_accounts ; | enterprisedb |
>> >> >>>> 128.199.224.132 | 1 | idle
>> >> >>>>
>> >> >>>> *6. Checking connection on pgpool server. connection is still open
>> >> from
>> >> >>>> pgpool to database*
>> >> >>>>
>> >> >>>> ps -ef|grep edb
>> >> >>>> enterpr+ 24170 24162 0 06:51 ? 00:00:00 pgpool:
>> enterprisedb
>> >> edb
>> >> >>>> 128.199.222.92(34402) idle
>> >> >>>>
>> >> >>>> *7. After being idle for more than 60 seconds, connections are
>> still
>> >> open
>> >> >>>> from pgpool and on database.Connection is removed from pgpool
>> server
>> >> after
>> >> >>>> I quit from the psql terminal but still present in the database as
>> >> show
>> >> >>>> below:*
>> >> >>>> Sat 01 Aug 2020 07:34:26 AM UTC (every 1s)
>> >> >>>>
>> >> >>>> pid | query | usename | client_addr | count |
>> state
>> >> >>>>
>> ------+--------------+--------------+-----------------+-------+-------
>> >> >>>> 3420 | DISCARD ALL | enterprisedb | 128.199.224.132 | 1 |
>> idle
>> >> >>>>
>> >> >>>>
>> >> >>>>
>> >> >>>> *Scenario2:*
>> >> >>>>
>> >> >>>> max_pool=1
>> >> >>>> num_init_children=100
>> >> >>>> serialize_accept=on
>> >> >>>> child_max_connections=0
>> >> >>>> child_life_time=0
>> >> >>>> connection_life_time=0
>> >> >>>> client_idle_limit=60
>> >> >>>>
>> >> >>>> *1. Connected to Pgpool and ran a query with \watch 1:*
>> >> >>>> edb=# \! date
>> >> >>>> Sat Aug 1 07:38:45 UTC 2020
>> >> >>>> select count(*) from pgbench_accounts ;
>> >> >>>> \watch 1
>> >> >>>> edb=# select count(*) from pgbench_accounts ;
>> >> >>>> count
>> >> >>>> ---------
>> >> >>>> 6000000
>> >> >>>> (1 row)
>> >> >>>>
>> >> >>>>
>> >> >>>> *2. Checking session in database, one session is active from
>> pgpool*
>> >> >>>>
>> >> >>>> Sat 01 Aug 2020 07:39:55 AM UTC
>> (every 1s)
>> >> >>>>
>> >> >>>> pid | query | usename |
>> >> >>>> client_addr | count | state
>> >> >>>>
>> >> >>>>
>> >>
>> -------+-----------------------------------------+--------------+-----------------+-------+--------
>> >> >>>> 13427 | select count(*) from pgbench_accounts ; | enterprisedb |
>> >> >>>> 128.199.224.132 | 1 | active
>> >> >>>>
>> >> >>>>
>> >> >>>> *3. Stopped the query after sometime using Ctrl-C but session is
>> still
>> >> >>>> open*
>> >> >>>> Sat 01 Aug 2020 07:41:39 AM UTC (every 1s)
>> >> >>>>
>> >> >>>> count
>> >> >>>> ---------
>> >> >>>> 6000000
>> >> >>>> ^Cedb=#
>> >> >>>> edb=#
>> >> >>>>
>> >> >>>> *4. Checking session in database, state is now idle*
>> >> >>>>
>> >> >>>> Sat 01 Aug 2020 07:42:12 AM UTC
>> (every 1s)
>> >> >>>>
>> >> >>>> pid | query | usename |
>> >> >>>> client_addr | count | state
>> >> >>>>
>> >> >>>>
>> >>
>> -------+-----------------------------------------+--------------+-----------------+-------+-------
>> >> >>>> 13427 | select count(*) from pgbench_accounts ; | enterprisedb |
>> >> >>>> 128.199.224.132 | 1 | idle
>> >> >>>> (1 row)
>> >> >>>>
>> >> >>>>
>> >> >>>> *5. Checking session in database after 2 minutes, there is no
>> session
>> >> in
>> >> >>>> the database.*
>> >> >>>>
>> >> >>>> Sat 01 Aug 2020 07:42:42 AM UTC (every 1s)
>> >> >>>>
>> >> >>>> pid | query | usename | client_addr | count | state
>> >> >>>> -----+-------+---------+-------------+-------+-------
>> >> >>>> (0 rows)
>> >> >>>>
>> >> >>>>
>> >> >>>> *6. Checking connection on pgpool server. No connection open in
>> >> pgpool to
>> >> >>>> database*
>> >> >>>> ps -ef|grep edb
>> >> >>>>
>> >> >>>>
>> >> >>>> *Observations:*
>> >> >>>>
>> >> >>>> With client_idle_limit of 60 seconds, all connections are closed
>> after
>> >> >>>> being idle for more than 1 minute. I can see psql session in
>> database
>> >> is
>> >> >>>> still present as shown below, because
>> >> >>>> I did not quit from psql terminal yet:
>> >> >>>>
>> >> >>>> [root at master ~]# ps -ef |grep 128.199.224.132
>> >> >>>> enterpr+ 13193 28563 0 07:38 pts/0 00:00:00 /bin/bash
>> /bin/psql -p
>> >> >>>> 9999 -h 128.199.224.132
>> >> >>>> enterpr+ 13198 13193 0 07:38 pts/0 00:00:00 /bin/psql.bin -p
>> 9999
>> >> -h
>> >> >>>> 128.199.224.132
>> >> >>>>
>> >> >>>>
>> >> >>>> From scenario 2( client_idle_limit = 60), we can say that when
>> >> >>>> client_idle_limit is triggered client is disconnected, no database
>> >> >>>> connection is in use but the session still remains on server.If i
>> >> start
>> >> >>>> running query
>> >> >>>> on same psql session, it will first reset connection and then run
>> the
>> >> >>>> query, this will again create a new connection to the database.
>> >> >>>>
>> >> >>>> From scenario 1(connection_life_time = 60), there is no real
>> benefit I
>> >> >>>> see. I assumed the connections(DISCARD ALL) present in database
>> will
>> >> be
>> >> >>>> reused but each time I connected to the database, it created a new
>> >> >>>> connection as seen below:
>> >> >>>>
>> >> >>>> pid | query | usename | client_addr | count |
>> state
>> >> >>>>
>> >> -------+--------------+--------------+-----------------+-------+-------
>> >> >>>> 12895 | | enterprisedb | 128.199.224.132 | 1 |
>> idle
>> >> >>>> 3420 | DISCARD ALL | enterprisedb | 128.199.224.132 | 1 |
>> idle
>> >> >>>> 12531 | DISCARD ALL | enterprisedb | 128.199.224.132 | 1 |
>> idle
>> >> >>>> 12636 | DISCARD ALL | enterprisedb | 128.199.224.132 | 1 |
>> idle
>> >> >>>> 12698 | DISCARD ALL | enterprisedb | 128.199.224.132 | 1 |
>> idle
>> >> >>>> 12751 | DISCARD ALL | enterprisedb | 128.199.224.132 | 1 |
>> idle
>> >> >>>> 12773 | DISCARD ALL | enterprisedb | 128.199.224.132 | 1 |
>> idle
>> >> >>>> 12862 | DISCARD ALL | enterprisedb | 128.199.224.132 | 1 |
>> idle
>> >> >>>> 12878 | DISCARD ALL | enterprisedb | 128.199.224.132 | 1 |
>> idle
>> >> >>>> (9 rows)
>> >> >>>>
>> >> >>>>
>> >> >>>> Thanks and Regards,
>> >> >>>> Nikhil
>> >> >>>>
>> >> >>>>
>> >> >>>>
>> >> >>>>
>> >> >>>>
>> >> >>>> On Sat, Aug 1, 2020 at 6:45 PM Tatsuo Ishii <ishii at sraoss.co.jp>
>> >> wrote:
>> >> >>>>
>> >> >>>>> > Hi,
>> >> >>>>> >
>> >> >>>>> > Yes, we can see the pid
>> >> >>>>> >
>> >> >>>>> > show pool_pools;
>> >> >>>>> > pool_pid | start_time | pool_id | backend_id |
>> database |
>> >> >>>>> > username | create_time | majorversion | minorversion
>> |
>> >> >>>>> > pool_counter | pool_backendpid | pool_connected
>> >> >>>>> >
>> >> >>>>> > 18190 | 2020-08-01 06:14:41 | 0 | 1 | edb
>> |
>> >> >>>>> > enterprisedb | 2020-08-01 06:19:52 | 3 | 0
>> |
>> >> 1
>> >> >>>>> > | *29321* | 0
>> >> >>>>> > 18193 | 2020-08-01 06:14:41 | 0 | 1 | edb
>> |
>> >> >>>>> > enterprisedb | 2020-08-01 06:21:26 | 3 | 0
>> |
>> >> 1
>> >> >>>>> > | *29619 *| 0
>> >> >>>>> >
>> >> >>>>> >
>> >> >>>>> > select pid,query,usename,state from pg_stat_activity where
>> >> >>>>> > client_addr='128.199.224.132' group by usename,query,pid;
>> >> >>>>> > pid | query | usename | state
>> >> >>>>> > -------+--------------+--------------+-------
>> >> >>>>> > *29321 *| DISCARD ALL | enterprisedb | idle
>> >> >>>>> > *29619* | DISCARD ALL | enterprisedb | idle
>> >> >>>>>
>> >> >>>>> Assuming you executed "show pool_pools" long after 2020-08-01
>> >> >>>>> 06:21:26, that is very strange because connection_life_time
>> should
>> >> >>>>> have been already expired. I wonder if pgpool tried to
>> disconnect the
>> >> >>>>> connection but failed. To check what actually happend, can you
>> check
>> >> >>>>> ps status of pgpool process 18190 and 18193?
>> >> >>>>>
>> >> >>>>> Also it would be nice you can examine the socket status of
>> PostgreSQL
>> >> >>>>> backend 29321 and 29619, and pgpool socket status of process
>> 18190
>> >> and
>> >> >>>>> 18193?
>> >> >>>>>
>> >> >>>>> Best regards,
>> >> >>>>> --
>> >> >>>>> Tatsuo Ishii
>> >> >>>>> SRA OSS, Inc. Japan
>> >> >>>>> English: http://www.sraoss.co.jp/index_en.php
>> >> >>>>> Japanese:http://www.sraoss.co.jp
>> >> >>>>>
>> >> >>>>
>> >> > _______________________________________________
>> >> > pgpool-general mailing list
>> >> > pgpool-general at pgpool.net
>> >> > http://www.pgpool.net/mailman/listinfo/pgpool-general
>> >>
>>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://www.sraoss.jp/pipermail/pgpool-general/attachments/20200830/d75f1267/attachment-0001.html>
-------------- next part --------------
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [117-1] 2020-08-30 05:01:47: pid 31560: DEBUG: UNLOCKING select()
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [118-1] 2020-08-30 05:01:47: pid 31560: DEBUG: setting value no index value for parameter "health_check_period" source = 1
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [119-1] 2020-08-30 05:01:47: pid 31560: DEBUG: parameter "health_check_period" is an array type variable and allows index-free value as well
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [120-1] 2020-08-30 05:01:47: pid 31560: DEBUG: setting value no index value for parameter "health_check_timeout" source = 1
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [121-1] 2020-08-30 05:01:47: pid 31560: DEBUG: parameter "health_check_timeout" is an array type variable and allows index-free value as well
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [122-1] 2020-08-30 05:01:47: pid 31560: DEBUG: setting value no index value for parameter "health_check_user" source = 1
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [123-1] 2020-08-30 05:01:47: pid 31560: DEBUG: parameter "health_check_user" is an array type variable and allows index-free value as well
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [124-1] 2020-08-30 05:01:47: pid 31560: DEBUG: setting value no index value for parameter "health_check_password" source = 1
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [125-1] 2020-08-30 05:01:47: pid 31560: DEBUG: parameter "health_check_password" is an array type variable and allows index-free value as well
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [126-1] 2020-08-30 05:01:47: pid 31560: DEBUG: setting value no index value for parameter "health_check_database" source = 1
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [127-1] 2020-08-30 05:01:47: pid 31560: DEBUG: parameter "health_check_database" is an array type variable and allows index-free value as well
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [128-1] 2020-08-30 05:01:47: pid 31560: DEBUG: setting value no index value for parameter "health_check_max_retries" source = 1
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [129-1] 2020-08-30 05:01:47: pid 31560: DEBUG: parameter "health_check_max_retries" is an array type variable and allows index-free value as well
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [130-1] 2020-08-30 05:01:47: pid 31560: DEBUG: setting value no index value for parameter "health_check_retry_delay" source = 1
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [131-1] 2020-08-30 05:01:47: pid 31560: DEBUG: parameter "health_check_retry_delay" is an array type variable and allows index-free value as well
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [132-1] 2020-08-30 05:01:47: pid 31560: DEBUG: setting value no index value for parameter "connect_timeout" source = 1
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [133-1] 2020-08-30 05:01:47: pid 31560: DEBUG: parameter "connect_timeout" is an array type variable and allows index-free value as well
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [134-1] 2020-08-30 05:01:47: pid 31560: DEBUG: setting "backend_flag0" flag: 0000
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [135-1] 2020-08-30 05:01:47: pid 31560: DEBUG: setting "backend_flag1" flag: 0000
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [136-1] 2020-08-30 05:01:47: pid 31560: WARNING: "pool_conn_dbname" is depreciated, use "health_check_database" to configure health check database
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [137-1] 2020-08-30 05:01:47: pid 31560: DEBUG: setting value no index value for parameter "health_check_database" source = 0
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [138-1] 2020-08-30 05:01:47: pid 31560: DEBUG: parameter "health_check_database" is an array type variable and allows index-free value as well
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [139-1] 2020-08-30 05:01:47: pid 31560: DEBUG: initializing pool configuration
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [139-2] 2020-08-30 05:01:47: pid 31560: DETAIL: num_backends: 2 total_weight: 1.000000
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [140-1] 2020-08-30 05:01:47: pid 31560: DEBUG: initializing pool configuration
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [140-2] 2020-08-30 05:01:47: pid 31560: DETAIL: backend 0 weight: 0.000000 flag: 0000
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [141-1] 2020-08-30 05:01:47: pid 31560: DEBUG: initializing pool configuration
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [141-2] 2020-08-30 05:01:47: pid 31560: DETAIL: backend 1 weight: 2147483647.000000 flag: 0000
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [142-1] 2020-08-30 05:01:47: pid 31560: DEBUG: initializing pool configuration
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [142-2] 2020-08-30 05:01:47: pid 31560: DETAIL: num_backends: 2 total_weight: 1.000000
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [143-1] 2020-08-30 05:01:47: pid 31560: DEBUG: initializing pool configuration
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [143-2] 2020-08-30 05:01:47: pid 31560: DETAIL: backend 0 weight: 0.000000 flag: 0000
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [144-1] 2020-08-30 05:01:47: pid 31560: DEBUG: initializing pool configuration
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [144-2] 2020-08-30 05:01:47: pid 31560: DETAIL: backend 1 weight: 2147483647.000000 flag: 0000
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [145-1] 2020-08-30 05:01:47: pid 31560: DEBUG: I am 31560 accept fd 7
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [146-1] 2020-08-30 05:01:47: pid 31560: LOG: new connection received
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [146-2] 2020-08-30 05:01:47: pid 31560: DETAIL: connecting host=standby1 port=58556
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [147-1] 2020-08-30 05:01:47: pid 31560: DEBUG: reading startup packet
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [147-2] 2020-08-30 05:01:47: pid 31560: DETAIL: Protocol Major: 1234 Minor: 5679 database: user:
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [148-1] 2020-08-30 05:01:47: pid 31560: DEBUG: selecting backend connection
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [148-2] 2020-08-30 05:01:47: pid 31560: DETAIL: SSLRequest from client
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [149-1] 2020-08-30 05:01:47: pid 31560: DEBUG: reading startup packet
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [149-2] 2020-08-30 05:01:47: pid 31560: DETAIL: application_name: psql.bin
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [150-1] 2020-08-30 05:01:47: pid 31560: DEBUG: reading startup packet
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [150-2] 2020-08-30 05:01:47: pid 31560: DETAIL: Protocol Major: 3 Minor: 0 database: edb user: enterprisedb
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [151-1] 2020-08-30 05:01:47: pid 31560: DEBUG: creating new connection to backend
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [151-2] 2020-08-30 05:01:47: pid 31560: DETAIL: connecting 0 backend
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [152-1] 2020-08-30 05:01:47: pid 31560: DEBUG: creating new connection to backend
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [152-2] 2020-08-30 05:01:47: pid 31560: DETAIL: connecting 1 backend
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [153-1] 2020-08-30 05:01:47: pid 31560: DEBUG: authentication backend
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [153-2] 2020-08-30 05:01:47: pid 31560: DETAIL: auth kind:5
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [154-1] 2020-08-30 05:01:47: pid 31560: WARNING: unable to get password, password file descriptor is NULL
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [155-1] 2020-08-30 05:01:47: pid 31560: LOG: using clear text authentication with frontend
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [155-2] 2020-08-30 05:01:47: pid 31560: DETAIL: backend will still use md5 auth
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [155-3] 2020-08-30 05:01:47: pid 31560: HINT: you can disable this behavior by setting allow_clear_text_frontend_auth to off
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [156-1] 2020-08-30 05:01:47: pid 31560: WARNING: unable to get password, password file descriptor is NULL
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [157-1] 2020-08-30 05:01:47: pid 31560: DEBUG: authentication backend: 0
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [157-2] 2020-08-30 05:01:47: pid 31560: DETAIL: trying md5 authentication
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [158-1] 2020-08-30 05:01:47: pid 31560: DEBUG: authentication backend: 1
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [158-2] 2020-08-30 05:01:47: pid 31560: DETAIL: trying md5 authentication
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [159-1] 2020-08-30 05:01:47: pid 31560: DEBUG: process parameter status
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [159-2] 2020-08-30 05:01:47: pid 31560: DETAIL: backend:0 name:"application_name" value:"psql.bin"
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [160-1] 2020-08-30 05:01:47: pid 31560: DEBUG: process parameter status
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [160-2] 2020-08-30 05:01:47: pid 31560: DETAIL: backend:1 name:"application_name" value:"psql.bin"
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [161-1] 2020-08-30 05:01:47: pid 31560: DEBUG: process parameter status
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [161-2] 2020-08-30 05:01:47: pid 31560: DETAIL: backend:0 name:"client_encoding" value:"UTF8"
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [162-1] 2020-08-30 05:01:47: pid 31560: DEBUG: process parameter status
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [162-2] 2020-08-30 05:01:47: pid 31560: DETAIL: backend:1 name:"client_encoding" value:"UTF8"
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [163-1] 2020-08-30 05:01:47: pid 31560: DEBUG: process parameter status
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [163-2] 2020-08-30 05:01:47: pid 31560: DETAIL: backend:0 name:"DateStyle" value:"Redwood, SHOW_TIME"
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [164-1] 2020-08-30 05:01:47: pid 31560: DEBUG: process parameter status
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [164-2] 2020-08-30 05:01:47: pid 31560: DETAIL: backend:1 name:"DateStyle" value:"Redwood, SHOW_TIME"
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [165-1] 2020-08-30 05:01:47: pid 31560: DEBUG: process parameter status
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [165-2] 2020-08-30 05:01:47: pid 31560: DETAIL: backend:0 name:"db_dialect" value:"redwood"
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [166-1] 2020-08-30 05:01:47: pid 31560: DEBUG: process parameter status
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [166-2] 2020-08-30 05:01:47: pid 31560: DETAIL: backend:1 name:"db_dialect" value:"redwood"
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [167-1] 2020-08-30 05:01:47: pid 31560: DEBUG: process parameter status
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [167-2] 2020-08-30 05:01:47: pid 31560: DETAIL: backend:0 name:"integer_datetimes" value:"on"
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [168-1] 2020-08-30 05:01:47: pid 31560: DEBUG: process parameter status
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [168-2] 2020-08-30 05:01:47: pid 31560: DETAIL: backend:1 name:"integer_datetimes" value:"on"
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [169-1] 2020-08-30 05:01:47: pid 31560: DEBUG: process parameter status
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [169-2] 2020-08-30 05:01:47: pid 31560: DETAIL: backend:0 name:"IntervalStyle" value:"postgres"
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [170-1] 2020-08-30 05:01:47: pid 31560: DEBUG: process parameter status
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [170-2] 2020-08-30 05:01:47: pid 31560: DETAIL: backend:1 name:"IntervalStyle" value:"postgres"
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [171-1] 2020-08-30 05:01:47: pid 31560: DEBUG: process parameter status
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [171-2] 2020-08-30 05:01:47: pid 31560: DETAIL: backend:0 name:"is_superuser" value:"on"
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [172-1] 2020-08-30 05:01:47: pid 31560: DEBUG: process parameter status
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [172-2] 2020-08-30 05:01:47: pid 31560: DETAIL: backend:1 name:"is_superuser" value:"on"
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [173-1] 2020-08-30 05:01:47: pid 31560: DEBUG: process parameter status
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [173-2] 2020-08-30 05:01:47: pid 31560: DETAIL: backend:0 name:"server_encoding" value:"UTF8"
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [174-1] 2020-08-30 05:01:47: pid 31560: DEBUG: process parameter status
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [174-2] 2020-08-30 05:01:47: pid 31560: DETAIL: backend:1 name:"server_encoding" value:"UTF8"
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [175-1] 2020-08-30 05:01:47: pid 31560: DEBUG: process parameter status
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [175-2] 2020-08-30 05:01:47: pid 31560: DETAIL: backend:0 name:"server_version" value:"11.6.13"
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [176-1] 2020-08-30 05:01:47: pid 31560: DEBUG: process parameter status
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [176-2] 2020-08-30 05:01:47: pid 31560: DETAIL: backend:1 name:"server_version" value:"11.6.13"
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [177-1] 2020-08-30 05:01:47: pid 31560: DEBUG: process parameter status
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [177-2] 2020-08-30 05:01:47: pid 31560: DETAIL: backend:0 name:"session_authorization" value:"enterprisedb"
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [178-1] 2020-08-30 05:01:47: pid 31560: DEBUG: process parameter status
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [178-2] 2020-08-30 05:01:47: pid 31560: DETAIL: backend:1 name:"session_authorization" value:"enterprisedb"
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [179-1] 2020-08-30 05:01:47: pid 31560: DEBUG: process parameter status
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [179-2] 2020-08-30 05:01:47: pid 31560: DETAIL: backend:0 name:"standard_conforming_strings" value:"on"
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [180-1] 2020-08-30 05:01:47: pid 31560: DEBUG: process parameter status
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [180-2] 2020-08-30 05:01:47: pid 31560: DETAIL: backend:1 name:"standard_conforming_strings" value:"on"
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [181-1] 2020-08-30 05:01:47: pid 31560: DEBUG: process parameter status
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [181-2] 2020-08-30 05:01:47: pid 31560: DETAIL: backend:0 name:"TimeZone" value:"Asia/Kolkata"
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [182-1] 2020-08-30 05:01:47: pid 31560: DEBUG: process parameter status
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [182-2] 2020-08-30 05:01:47: pid 31560: DETAIL: backend:1 name:"TimeZone" value:"Asia/Kolkata"
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [183-1] 2020-08-30 05:01:47: pid 31560: DEBUG: authentication backend
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [183-2] 2020-08-30 05:01:47: pid 31560: DETAIL: cp->info[i]:0x7fa2b1338000 pid:31550
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [184-1] 2020-08-30 05:01:47: pid 31560: DEBUG: authentication backend
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [184-2] 2020-08-30 05:01:47: pid 31560: DETAIL: cp->info[i]:0x7fa2b1338088 pid:28954
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [185-1] 2020-08-30 05:01:47: pid 31560: DEBUG: sending backend key data
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [185-2] 2020-08-30 05:01:47: pid 31560: DETAIL: send pid 28954 to frontend
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [186-1] 2020-08-30 05:01:47: pid 31560: DEBUG: selecting load balance node
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [186-2] 2020-08-30 05:01:47: pid 31560: DETAIL: selected backend id is 1
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [187-1] 2020-08-30 05:01:47: pid 31560: LOG: Query message from frontend.
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [187-2] 2020-08-30 05:01:47: pid 31560: DETAIL: query: "BEGIN;"
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [188-1] 2020-08-30 05:01:47: pid 31560: LOG: statement: BEGIN;
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [189-1] 2020-08-30 05:01:47: pid 31560: DEBUG: decide where to send the query
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [189-2] 2020-08-30 05:01:47: pid 31560: DETAIL: destination = 3 for query= "BEGIN;"
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [190-1] 2020-08-30 05:01:47: pid 31560: LOG: DB node id: 0 backend pid: 31550 statement: BEGIN;
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [191-1] 2020-08-30 05:01:47: pid 31560: DEBUG: waiting for query response
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [191-2] 2020-08-30 05:01:47: pid 31560: DETAIL: waiting for backend:0 to complete the query
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [192-1] 2020-08-30 05:01:47: pid 31560: LOG: DB node id: 1 backend pid: 28954 statement: BEGIN;
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [193-1] 2020-08-30 05:01:47: pid 31560: DEBUG: waiting for query response
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [193-2] 2020-08-30 05:01:47: pid 31560: DETAIL: waiting for backend:1 to complete the query
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [194-1] 2020-08-30 05:01:47: pid 31560: LOG: Query message from frontend.
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [194-2] 2020-08-30 05:01:47: pid 31560: DETAIL: query: "SELECT CURRENT_TIMESTAMP;"
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [195-1] 2020-08-30 05:01:47: pid 31560: LOG: statement: SELECT CURRENT_TIMESTAMP;
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [196-1] 2020-08-30 05:01:47: pid 31560: DEBUG: checking if query has INSERT INTO, FOR SHARE or FOR UPDATE
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [196-2] 2020-08-30 05:01:47: pid 31560: DETAIL: result = 0
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [197-1] 2020-08-30 05:01:47: pid 31560: DEBUG: decide where to send the query
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [197-2] 2020-08-30 05:01:47: pid 31560: DETAIL: destination = 2 for query= "SELECT CURRENT_TIMESTAMP;"
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [198-1] 2020-08-30 05:01:47: pid 31560: DEBUG: do_query: extended:0 query:"SELECT current_setting('transaction_isolation')"
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [198-2] 2020-08-30 05:01:47: pid 31560: CONTEXT: while getting transaction isolation
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [199-1] 2020-08-30 05:01:47: pid 31560: DEBUG: checking load balance precondtions. TSTATE:T wrting_trancation:0 failed_transaction:0 isolation:2
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [199-2] 2020-08-30 05:01:47: pid 31560: DETAIL: destination = 2 for query= "SELECT CURRENT_TIMESTAMP;"
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [200-1] 2020-08-30 05:01:47: pid 31560: DEBUG: selecting load balance node
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [200-2] 2020-08-30 05:01:47: pid 31560: DETAIL: selected backend id is 1
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [201-1] 2020-08-30 05:01:47: pid 31560: LOG: DB node id: 1 backend pid: 28954 statement: SELECT CURRENT_TIMESTAMP;
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [202-1] 2020-08-30 05:01:47: pid 31560: DEBUG: waiting for query response
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [202-2] 2020-08-30 05:01:47: pid 31560: DETAIL: waiting for backend:1 to complete the query
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [203-1] 2020-08-30 05:01:47: pid 31560: LOG: Query message from frontend.
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [203-2] 2020-08-30 05:01:47: pid 31560: DETAIL: query: "INSERT into t1 values(3);"
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [204-1] 2020-08-30 05:01:47: pid 31560: LOG: statement: INSERT into t1 values(3);
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [205-1] 2020-08-30 05:01:47: pid 31560: DEBUG: decide where to send the query
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [205-2] 2020-08-30 05:01:47: pid 31560: DETAIL: destination = 0 for query= "INSERT into t1 values(3);"
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [206-1] 2020-08-30 05:01:47: pid 31560: LOG: DB node id: 0 backend pid: 31550 statement: INSERT into t1 values(3);
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [207-1] 2020-08-30 05:01:47: pid 31560: DEBUG: waiting for query response
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [207-2] 2020-08-30 05:01:47: pid 31560: DETAIL: waiting for backend:0 to complete the query
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [208-1] 2020-08-30 05:01:47: pid 31560: DEBUG: not SET TRANSACTION READ ONLY
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [209-1] 2020-08-30 05:01:47: pid 31560: LOG: Query message from frontend.
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [209-2] 2020-08-30 05:01:47: pid 31560: DETAIL: query: "INSERT into t1 values(4);"
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [210-1] 2020-08-30 05:01:47: pid 31560: LOG: statement: INSERT into t1 values(4);
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [211-1] 2020-08-30 05:01:47: pid 31560: DEBUG: decide where to send the query
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [211-2] 2020-08-30 05:01:47: pid 31560: DETAIL: destination = 0 for query= "INSERT into t1 values(4);"
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [212-1] 2020-08-30 05:01:47: pid 31560: LOG: DB node id: 0 backend pid: 31550 statement: INSERT into t1 values(4);
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [213-1] 2020-08-30 05:01:47: pid 31560: DEBUG: waiting for query response
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [213-2] 2020-08-30 05:01:47: pid 31560: DETAIL: waiting for backend:0 to complete the query
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [214-1] 2020-08-30 05:01:47: pid 31560: DEBUG: not SET TRANSACTION READ ONLY
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [215-1] 2020-08-30 05:01:47: pid 31560: LOG: Query message from frontend.
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [215-2] 2020-08-30 05:01:47: pid 31560: DETAIL: query: "select pg_sleep(5);"
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [216-1] 2020-08-30 05:01:47: pid 31560: LOG: statement: select pg_sleep(5);
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [217-1] 2020-08-30 05:01:47: pid 31560: DEBUG: function call walker, function name: "pg_sleep"
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [218-1] 2020-08-30 05:01:47: pid 31560: DEBUG: checking if query has INSERT INTO, FOR SHARE or FOR UPDATE
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [218-2] 2020-08-30 05:01:47: pid 31560: DETAIL: result = 0
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [219-1] 2020-08-30 05:01:47: pid 31560: DEBUG: decide where to send the query
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [219-2] 2020-08-30 05:01:47: pid 31560: DETAIL: destination = 2 for query= "select pg_sleep(5);"
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [220-1] 2020-08-30 05:01:47: pid 31560: DEBUG: checking load balance precondtions. TSTATE:T wrting_trancation:1 failed_transaction:0 isolation:2
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [220-2] 2020-08-30 05:01:47: pid 31560: DETAIL: destination = 2 for query= "select pg_sleep(5);"
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [221-1] 2020-08-30 05:01:47: pid 31560: DEBUG: function call walker, function name: "pg_sleep"
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [222-1] 2020-08-30 05:01:47: pid 31560: LOG: DB node id: 0 backend pid: 31550 statement: select pg_sleep(5);
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [223-1] 2020-08-30 05:01:47: pid 31560: DEBUG: waiting for query response
Aug 30 05:01:47 Pgpool-p pgpool[31560]: [223-2] 2020-08-30 05:01:47: pid 31560: DETAIL: waiting for backend:0 to complete the query
Aug 30 05:01:52 Pgpool-p pgpool[31560]: [224-1] 2020-08-30 05:01:52: pid 31560: DEBUG: function call walker, function name: "pg_sleep"
Aug 30 05:01:52 Pgpool-p pgpool[31560]: [225-1] 2020-08-30 05:01:52: pid 31560: LOG: Query message from frontend.
Aug 30 05:01:52 Pgpool-p pgpool[31560]: [225-2] 2020-08-30 05:01:52: pid 31560: DETAIL: query: "INSERT into t1 values(5);"
Aug 30 05:01:52 Pgpool-p pgpool[31560]: [226-1] 2020-08-30 05:01:52: pid 31560: LOG: statement: INSERT into t1 values(5);
Aug 30 05:01:52 Pgpool-p pgpool[31560]: [227-1] 2020-08-30 05:01:52: pid 31560: DEBUG: decide where to send the query
Aug 30 05:01:52 Pgpool-p pgpool[31560]: [227-2] 2020-08-30 05:01:52: pid 31560: DETAIL: destination = 0 for query= "INSERT into t1 values(5);"
Aug 30 05:01:52 Pgpool-p pgpool[31560]: [228-1] 2020-08-30 05:01:52: pid 31560: LOG: DB node id: 0 backend pid: 31550 statement: INSERT into t1 values(5);
Aug 30 05:01:52 Pgpool-p pgpool[31560]: [229-1] 2020-08-30 05:01:52: pid 31560: DEBUG: waiting for query response
Aug 30 05:01:52 Pgpool-p pgpool[31560]: [229-2] 2020-08-30 05:01:52: pid 31560: DETAIL: waiting for backend:0 to complete the query
Aug 30 05:01:52 Pgpool-p pgpool[31560]: [230-1] 2020-08-30 05:01:52: pid 31560: DEBUG: not SET TRANSACTION READ ONLY
Aug 30 05:01:52 Pgpool-p pgpool[31560]: [231-1] 2020-08-30 05:01:52: pid 31560: LOG: Query message from frontend.
Aug 30 05:01:52 Pgpool-p pgpool[31560]: [231-2] 2020-08-30 05:01:52: pid 31560: DETAIL: query: "UPDATE t1 set id=4 where id=5;"
Aug 30 05:01:52 Pgpool-p pgpool[31560]: [232-1] 2020-08-30 05:01:52: pid 31560: LOG: statement: UPDATE t1 set id=4 where id=5;
Aug 30 05:01:52 Pgpool-p pgpool[31560]: [233-1] 2020-08-30 05:01:52: pid 31560: DEBUG: decide where to send the query
Aug 30 05:01:52 Pgpool-p pgpool[31560]: [233-2] 2020-08-30 05:01:52: pid 31560: DETAIL: destination = 0 for query= "UPDATE t1 set id=4 where id=5;"
Aug 30 05:01:52 Pgpool-p pgpool[31560]: [234-1] 2020-08-30 05:01:52: pid 31560: LOG: DB node id: 0 backend pid: 31550 statement: UPDATE t1 set id=4 where id=5;
Aug 30 05:01:52 Pgpool-p pgpool[31560]: [235-1] 2020-08-30 05:01:52: pid 31560: DEBUG: waiting for query response
Aug 30 05:01:52 Pgpool-p pgpool[31560]: [235-2] 2020-08-30 05:01:52: pid 31560: DETAIL: waiting for backend:0 to complete the query
Aug 30 05:01:52 Pgpool-p pgpool[31560]: [236-1] 2020-08-30 05:01:52: pid 31560: DEBUG: not SET TRANSACTION READ ONLY
Aug 30 05:01:52 Pgpool-p pgpool[31560]: [237-1] 2020-08-30 05:01:52: pid 31560: LOG: Query message from frontend.
Aug 30 05:01:52 Pgpool-p pgpool[31560]: [237-2] 2020-08-30 05:01:52: pid 31560: DETAIL: query: "END;"
Aug 30 05:01:52 Pgpool-p pgpool[31560]: [238-1] 2020-08-30 05:01:52: pid 31560: LOG: statement: END;
Aug 30 05:01:52 Pgpool-p pgpool[31560]: [239-1] 2020-08-30 05:01:52: pid 31560: DEBUG: decide where to send the query
Aug 30 05:01:52 Pgpool-p pgpool[31560]: [239-2] 2020-08-30 05:01:52: pid 31560: DETAIL: destination = 3 for query= "END;"
Aug 30 05:01:52 Pgpool-p pgpool[31560]: [240-1] 2020-08-30 05:01:52: pid 31560: LOG: DB node id: 1 backend pid: 28954 statement: END;
Aug 30 05:01:52 Pgpool-p pgpool[31560]: [241-1] 2020-08-30 05:01:52: pid 31560: DEBUG: waiting for query response
Aug 30 05:01:52 Pgpool-p pgpool[31560]: [241-2] 2020-08-30 05:01:52: pid 31560: DETAIL: waiting for backend:1 to complete the query
Aug 30 05:01:52 Pgpool-p pgpool[31560]: [242-1] 2020-08-30 05:01:52: pid 31560: LOG: DB node id: 0 backend pid: 31550 statement: END;
Aug 30 05:01:52 Pgpool-p pgpool[31560]: [243-1] 2020-08-30 05:01:52: pid 31560: DEBUG: waiting for query response
Aug 30 05:01:52 Pgpool-p pgpool[31560]: [243-2] 2020-08-30 05:01:52: pid 31560: DETAIL: waiting for backend:0 to complete the query
Aug 30 05:01:52 Pgpool-p pgpool[31560]: [244-1] 2020-08-30 05:01:52: pid 31560: LOG: Terminate message from frontend.
Aug 30 05:01:52 Pgpool-p pgpool[31560]: [245-1] 2020-08-30 05:01:52: pid 31560: LOG: statement: DISCARD ALL
Aug 30 05:01:52 Pgpool-p pgpool[31560]: [246-1] 2020-08-30 05:01:52: pid 31560: DEBUG: decide where to send the query
Aug 30 05:01:52 Pgpool-p pgpool[31560]: [246-2] 2020-08-30 05:01:52: pid 31560: DETAIL: destination = 3 for query= " DISCARD ALL"
Aug 30 05:01:52 Pgpool-p pgpool[31560]: [247-1] 2020-08-30 05:01:52: pid 31560: LOG: DB node id: 0 backend pid: 31550 statement: DISCARD ALL
Aug 30 05:01:52 Pgpool-p pgpool[31560]: [248-1] 2020-08-30 05:01:52: pid 31560: DEBUG: waiting for query response
Aug 30 05:01:52 Pgpool-p pgpool[31560]: [248-2] 2020-08-30 05:01:52: pid 31560: DETAIL: waiting for backend:0 to complete the query
Aug 30 05:01:52 Pgpool-p pgpool[31560]: [249-1] 2020-08-30 05:01:52: pid 31560: LOG: DB node id: 1 backend pid: 28954 statement: DISCARD ALL
Aug 30 05:01:52 Pgpool-p pgpool[31560]: [250-1] 2020-08-30 05:01:52: pid 31560: DEBUG: waiting for query response
Aug 30 05:01:52 Pgpool-p pgpool[31560]: [250-2] 2020-08-30 05:01:52: pid 31560: DETAIL: waiting for backend:1 to complete the query
Aug 30 05:01:52 Pgpool-p pgpool[31560]: [251-1] 2020-08-30 05:01:52: pid 31560: DEBUG: setting backend connection close timer
Aug 30 05:01:52 Pgpool-p pgpool[31560]: [251-2] 2020-08-30 05:01:52: pid 31560: DETAIL: close time 1598763712
Aug 30 05:01:52 Pgpool-p pgpool[31560]: [252-1] 2020-08-30 05:01:52: pid 31560: DEBUG: setting backend connection close timer
Aug 30 05:01:52 Pgpool-p pgpool[31560]: [252-2] 2020-08-30 05:01:52: pid 31560: DETAIL: setting alarm after 10 seconds
Aug 30 05:04:06 Pgpool-p pgpool[31560]: [253-1] 2020-08-30 05:04:06: pid 31560: DEBUG: LOCKING select()
More information about the pgpool-general
mailing list