[pgpool-general: 7232] Re: Idle connection in database

Tatsuo Ishii ishii at sraoss.co.jp
Mon Aug 31 09:05:59 JST 2020


Wait. It appears that the patch has a drawback: serious performance
degradation.

pgbench -c 10 -n -p 11000 -C -t 10 test

With connection_life_time = 10
tps = 3.316286 (including connections establishing)
tps = 3.680803 (excluding connections establishing)

Without connection_life_time = 10
tps = 269.660238 (including connections establishing)
tps = 280.479690 (excluding connections establishing)

Let me think if I coould enhance this...

> Hi Nikhil,
> 
> Ok, here is a patch to fix the problem.
> 
> If serialize_accept is enabled, pgpool process tries to acquire
> semaphore locking so that there's only one process which can issue
> accept(2). Unfortunately if connection_life_time is enabled, an alarm
> is set right before the semaphore locking. So when the alarm fires,
> nothing happens because the process is waiting for semaphore locking.
> 
> To fix this, "the alarm has been set" flag is added. If the flag is
> set, keep on checking for connection_life_time (plus margin) seconds
> until the alarm is fired, then expires the connection to backend.
> 
> Patch attached.
> 
>>> Hi Tatsuo,
>>> 
>>> I was thinking on that line initially that may be because of
>>> serialize_accept it is not working but I didn't dwell into it much and
>>> didn't test it.
>>> 
>>> Thanks for your input Tatsuo, you have been of immense help to find this
>>> problem.
>>> 
>>> Will this fix, when it is done,  be included in all 4.0 and 4.1 versions?
>> 
>> Not sure if there's actually a fix, but if there were a fix for this,
>> it will be definitely included in 4.0 and 4.1 branches.
>> 
>>> On Sun, Aug 30, 2020, 14:08 Tatsuo Ishii <ishii at sraoss.co.jp> wrote:
>>> 
>>>> Ok, I found that if following is set:
>>>>
>>>> serialize_accept=on
>>>>
>>>> then, connection_life_time does not work. (The alarm is not
>>>> fired). Don't know why but I am going to fix this.
>>>>
>>>> > Hi Tatsuo,
>>>> >
>>>> > I am using Pgpool v4.1.1.
>>>> >
>>>> > I have seen similiar behaviour in v4.0.9 as well.
>>>> >
>>>> > Thanks and Regards,
>>>> > Nikhil
>>>> >
>>>> > On Sun, Aug 30, 2020, 13:11 Tatsuo Ishii <ishii at sraoss.co.jp> wrote:
>>>> >
>>>> >> Ok, I have tried with your test data and pgpool settings. Also I added
>>>> >> log_disconnections to postgresql.conf so that when Pgpool-II
>>>> >> disconnects backend.  However I was not able to reproduce your
>>>> >> problem. Pgpool-II worked as expected (10 seconds after the test
>>>> >> script ends, connection was terminated on all backends).
>>>> >>
>>>> >> What version of Pgpool-II are you using?
>>>> >>
>>>> >> > Hi Tatsuo,
>>>> >> >
>>>> >> >
>>>> >> > No, because my primary has node ID 0 and standby has node ID 1.
>>>> >> >
>>>> >> > Patch will help if my primary node ID is not 0 rite?
>>>> >> >
>>>> >> > Thanks and Regards,
>>>> >> > Nikhil
>>>> >> >
>>>> >> >
>>>> >> > On Sun, Aug 30, 2020, 12:19 Tatsuo Ishii <ishii at sraoss.co.jp> wrote:
>>>> >> >
>>>> >> >> Before these tests, have applied the patch?
>>>> >> >>
>>>> >> >> > 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
>>>> >> >> >>> >>
>>>> >> >> >>>
>>>> >> >> >>
>>>> >> >>
>>>> >>
>>>>
>> _______________________________________________
>> pgpool-general mailing list
>> pgpool-general at pgpool.net
>> http://www.pgpool.net/mailman/listinfo/pgpool-general


More information about the pgpool-general mailing list