[pgpool-general: 7640] Re: Problems with response time

Bo Peng pengbo at sraoss.co.jp
Wed Jul 14 16:46:15 JST 2021


Thank you for sharing pgpool logs.

I can't figure out the cause from the pgpool log.
Was some messages output in the postgresql log during that time? 

Is it possible to enbale pgpool debug log?

 -----------
 # vi /path/to/pgpool.conf
 ...
 log_min_messages = debug1

 # pgpool -f /path/to/pgpool.conf reload
 -----------

> This is the pgpool log when icinga connects and response time is about 5 seconds: 

Is the slow response time always 5 seconds?

If the logs don't show the cause, you may need to track the system calls using "strace".

On Tue, 6 Jul 2021 09:10:32 +0200 (CEST)
Francesco Mazzi <fmazzi at comune.genova.it> wrote:

> This is the pgpool log when icinga connects and response time is about 5 seconds: 
> 
> Jul 6 03:44:42 xxxxxxx pgpool: 2021-07-06 03:44:42: pid 26292: LOG: new connection received 
> Jul 6 03:44:42 xxxxxxx pgpool: 2021-07-06 03:44:42: pid 26292: DETAIL: connecting host=192.168.xxx.xxx port=47510 
> Jul 6 03:44:42 xxxxxxx pgpool: 2021-07-06 03:44:42: pid 1556: LOG: child process with pid: 26233 exits with status 256 
> Jul 6 03:44:42 xxxxxxx pgpool: 2021-07-06 03:44:42: pid 1556: LOG: fork a new child process with pid: 26366 
> Jul 6 03:44:47 xxxxxxx pgpool: 2021-07-06 03:44:47: pid 26292: LOG: DB node id: 1 backend pid: 16796 statement: SELECT version() 
> Jul 6 03:44:47 xxxxxxx pgpool: 2021-07-06 03:44:47: pid 26292: LOG: DB node id: 0 backend pid: 29378 statement: DISCARD ALL 
> Jul 6 03:44:47 xxxxxxx pgpool: 2021-07-06 03:44:47: pid 26292: LOG: DB node id: 1 backend pid: 16796 statement: DISCARD ALL 
> Jul 6 03:44:47 xxxxxxx pgpool: 2021-07-06 03:44:47: pid 26292: LOG: frontend disconnection: session time: 0:00:05.068 user=xxxxxx database=template1 
> host=192.168.xxx.xxx port=47510 
> 
> This is a icinga connection with fast response time: 
> 
> Jul 6 03:49:44 xxxxxx pgpool: 2021-07-06 03:49:44: pid 26366: LOG: new connection received 
> Jul 6 03:49:44 xxxxxx pgpool: 2021-07-06 03:49:44: pid 26366: DETAIL: connecting host=192.168.xxx.xxx port=53152 
> Jul 6 03:49:44 xxxxxx pgpool: 2021-07-06 03:49:44: pid 26366: LOG: DB node id: 1 backend pid: 31761 statement: SELECT version() 
> Jul 6 03:49:44 xxxxxx pgpool: 2021-07-06 03:49:44: pid 26366: LOG: DB node id: 1 backend pid: 31761 statement: DISCARD ALL 
> Jul 6 03:49:44 xxxxxx pgpool: 2021-07-06 03:49:44: pid 26366: LOG: DB node id: 2 backend pid: 2980 statement: DISCARD ALL 
> Jul 6 03:49:44 xxxxxx pgpool: 2021-07-06 03:49:44: pid 26366: LOG: frontend disconnection: session time: 0:00:00.044 user=xxxxxx database=template1 
> host=192.168.xxx.xxx port=53152 
> Jul 6 03:49:47 xxxxxx pgpool: 2021-07-06 03:49:47: pid 1556: LOG: child process with pid: 26292 exits with status 256 
> Jul 6 03:49:47 xxxxxx pgpool: 2021-07-06 03:49:47: pid 1556: LOG: fork a new child process with pid: 26419 
> 
> I don't see any difference. 
> 
> 
> Da: "Bo Peng" <pengbo at sraoss.co.jp> 
> A: "fmazzi" <fmazzi at comune.genova.it> 
> Cc: "pgpool-general" <pgpool-general at pgpool.net> 
> Inviato: Martedì, 6 luglio 2021 7:59:43 
> Oggetto: [pgpool-general: 7633] Re: Problems with response time 
> 
> Hello, 
> 
> > I disabled connection pooling in HikariCP, but problem persists. Any ideas? 
> > Thanks 
> 
> You may need to check pgpool and postresql logs 
> to figure out the cause. 
> 
> > Da: "fmazzi" <fmazzi at comune.genova.it> 
> > A: "valsaraj pv" <valsarajpv at gmail.com> 
> > Cc: "pgpool-general" <pgpool-general at pgpool.net> 
> > Inviato: Giovedì, 1 luglio 2021 12:29:28 
> > Oggetto: [pgpool-general: 7614] Re: Problems with response time 
> > 
> > There is an application that uses HikariCP for connection pooling, maybe is this the problem? 
> > 
> > 
> > Da: "fmazzi" <fmazzi at comune.genova.it> 
> > A: "valsaraj pv" <valsarajpv at gmail.com> 
> > Cc: "pgpool-general" <pgpool-general at pgpool.net> 
> > Inviato: Giovedì, 1 luglio 2021 9:34:48 
> > Oggetto: [pgpool-general: 7610] Re: Problems with response time 
> > 
> > Response time is checked every 5 minutes from icinga with a connection to db, see attachments with response time graph and alerts. 
> > 
> > 
> > Da: "valsaraj pv" <valsarajpv at gmail.com> 
> > A: "fmazzi" <fmazzi at comune.genova.it> 
> > Cc: "pgpool-general" <pgpool-general at pgpool.net> 
> > Inviato: Mercoledì, 30 giugno 2021 17:24:58 
> > Oggetto: [pgpool-general: 7608] Re: Problems with response time 
> > 
> > Since there is only 2 unique connection set, max_pool can be set minimum 2. 
> > 
> > Would you share how did you check response time? 
> > 
> > 
> > On Wed, 30 Jun 2021, 7:19 pm Francesco Mazzi, < [ mailto:fmazzi at comune.genova.it | fmazzi at comune.genova.it ] > wrote: 
> > 
> > 
> > 
> > Sorry, I think I wrote wrong things. max pool=4 should be enough because there are only 2 unique couples of user/db 
> > 
> > 
> > Da: "fmazzi" < [ mailto:fmazzi at comune.genova.it | fmazzi at comune.genova.it ] > 
> > A: "Bo Peng" < [ mailto:pengbo at sraoss.co.jp | pengbo at sraoss.co.jp ] > 
> > Cc: "pgpool-general" < [ mailto:pgpool-general at pgpool.net | pgpool-general at pgpool.net ] > 
> > Inviato: Mercoledì, 30 giugno 2021 15:42:21 
> > Oggetto: [pgpool-general: 7606] Re: Problems with response time 
> > 
> > Hi, we enabled connections and disconnections log. There are about total 56 connections, 42 of them are from an unique user, half to a db and another half to another db, so I think we need at least 21 connections cached for this application. 
> > In this moment we have num_init_children=110 and max_pool=4 , should we increase max_pool to be at least 21? 
> > child_life_time and connection_life_time are set to zero. 
> > Thank you. 
> > 
> > 
> > Da: "Bo Peng" < [ mailto:pengbo at sraoss.co.jp | pengbo at sraoss.co.jp ] > 
> > A: "fmazzi" < [ mailto:fmazzi at comune.genova.it | fmazzi at comune.genova.it ] > 
> > Cc: "pgpool-general" < [ mailto:pgpool-general at pgpool.net | pgpool-general at pgpool.net ] > 
> > Inviato: Mercoledì, 30 giugno 2021 5:20:41 
> > Oggetto: Re: [pgpool-general: 7601] Problems with response time 
> > 
> > Hello, 
> > 
> > On Tue, 29 Jun 2021 15:22:51 +0200 (CEST) 
> > Francesco Mazzi < [ mailto:fmazzi at comune.genova.it | fmazzi at comune.genova.it ] > wrote: 
> > 
> > > Hello, we have two instances of pgpool 4.2.2, one leader and one stand by, in front of a postgresql cluster of 3 nodes (one read/write and two read only), version 12. 
> > > We noticed a strange behaviour about connection response time, both with active and standby pgpool: sometimes response time (database connection) suddenly changes from about 0,02s to about 5s and then it comes back to 0,02s. CPU load on server remains very low. 
> > > We raised num_init_children to 110 but nothing changed. In this moment database it isn't very used, so why there are these low response times? 
> > 
> > > We noticed a strange behaviour about connection response time, both with active and standby pgpool: sometimes response time (database connection) suddenly changes from about 0,02s to about 5s and then it comes back to 0,02s. CPU load on server remains very low. 
> > > We raised num_init_children to 110 but nothing changed. In this moment database it isn't very used, so why there are these low response times? 
> > 
> > The difference in database connection response time may be caused by the effect of connection cache. 
> > Creating a new connection to PostgreSQL takes longer than reusing the cached connections. 
> > 
> > In the following cases, Pgpool-II creates new connections to PostgreSQL: 
> > 
> > - The connections to the specified database has not been created yet. 
> > - If the number of cached connections exceeds specified max_pool, 
> > the oldest connection will be discarded, then Pgpool-II use that slot for a new connection. 
> > - Duo to the settings of child_life_time, connection_life_time, 
> > the cached connections are terminated. 
> > 
> > To figure out the cause, you can check pgpool logs if it is a new connection to PostgreSQL. 
> > 
> > -- 
> > Bo Peng < [ mailto:pengbo at sraoss.co.jp | pengbo at sraoss.co.jp ] > 
> > SRA OSS, Inc. Japan 
> > [ http://www.sraoss.co.jp/ | http://www.sraoss.co.jp/ ] 
> > 
> > 
> > 
> > 
> > Click [ https://www.mailcontrol.com/sr/MZbqvYs5QwJvpeaetUwhCQ== | here ] to report this email as spam. 
> > _______________________________________________ 
> > pgpool-general mailing list 
> > [ mailto:pgpool-general at pgpool.net | pgpool-general at pgpool.net ] 
> > [ http://www.pgpool.net/mailman/listinfo/pgpool-general | http://www.pgpool.net/mailman/listinfo/pgpool-general ] 
> > _______________________________________________ 
> > pgpool-general mailing list 
> > [ mailto:pgpool-general at pgpool.net | pgpool-general at pgpool.net ] 
> > [ http://www.pgpool.net/mailman/listinfo/pgpool-general | 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 
> > 
> > _______________________________________________ 
> > pgpool-general mailing list 
> > pgpool-general at pgpool.net 
> > http://www.pgpool.net/mailman/listinfo/pgpool-general 
> 
> 
> -- 
> Bo Peng <pengbo at sraoss.co.jp> 
> SRA OSS, Inc. Japan 
> http://www.sraoss.co.jp/ 
> _______________________________________________ 
> pgpool-general mailing list 
> pgpool-general at pgpool.net 
> http://www.pgpool.net/mailman/listinfo/pgpool-general 


-- 
Bo Peng <pengbo at sraoss.co.jp>
SRA OSS, Inc. Japan
http://www.sraoss.co.jp/


More information about the pgpool-general mailing list