[pgpool-general: 7233] Re: Idle connection in database
Tatsuo Ishii
ishii at sraoss.co.jp
Mon Aug 31 10:32:12 JST 2020
Ok, attached is a new version of patch. I confirmed that performance
was not changed.
> 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
> _______________________________________________
> pgpool-general mailing list
> pgpool-general at pgpool.net
> http://www.pgpool.net/mailman/listinfo/pgpool-general
-------------- next part --------------
A non-text attachment was scrubbed...
Name: connection_life_time_v2.diff
Type: text/x-patch
Size: 3712 bytes
Desc: not available
URL: <http://www.sraoss.jp/pipermail/pgpool-general/attachments/20200831/cd24cc67/attachment-0001.bin>
More information about the pgpool-general
mailing list