[pgpool-general: 5901] Re: pgpool frequnet authentication timeout
Pankaj Joshi
pankajjo02 at gmail.com
Tue Jan 30 01:51:30 JST 2018
Hello Muhammad,
I get the issue randomly like this
Jan 29 02:14:12 servername pgpool[4777]: [10140-1] 2018-01-29 02:14:12: pid
4777: LOG: authentication timeout
Jan 29 02:14:13 servername pgpool[4033]: [10124-1] 2018-01-29 02:14:13: pid
4033: LOG: authentication timeout
Jan 29 02:14:15 servername pgpool[22271]: [10021-1] 2018-01-29 02:14:15:
pid 22271: LOG: authentication timeout
Jan 29 02:14:15 servername pgpool[10270]: [10110-1] 2018-01-29 02:14:15:
pid 10270: LOG: authentication timeout
Jan 29 02:14:16 servername pgpool[4452]: [10136-1] 2018-01-29 02:14:16: pid
4452: LOG: authentication timeout
Jan 29 02:14:16 servername pgpool[5309]: [10132-1] 2018-01-29 02:14:16: pid
5309: LOG: authentication timeout
Jan 29 02:14:17 servername pgpool[19914]: [10057-1] 2018-01-29 02:14:17:
pid 19914: LOG: authentication timeout
Jan 29 02:14:18 servername pgpool[1976]: [10089-1] 2018-01-29 02:14:18: pid
1976: LOG: authentication timeout
Jan 29 02:14:19 servername pgpool[4437]: [10134-1] 2018-01-29 02:14:19: pid
4437: LOG: authentication timeout
Jan 29 02:14:19 servername pgpool[23122]: [10095-1] 2018-01-29 02:14:19:
pid 23122: LOG: authentication timeout
Jan 29 02:14:22 servername pgpool[19087]: [10003-1] 2018-01-29 02:14:22:
pid 19087: LOG: authentication timeout
Jan 29 03:50:12 servername pgpool[5306]: [10130-1] 2018-01-29 03:50:12: pid
5306: LOG: authentication timeout
Jan 29 03:50:14 servername pgpool[26905]: [10142-1] 2018-01-29 03:50:14:
pid 26905: LOG: authentication timeout
Jan 29 03:50:24 servername pgpool[27600]: [10162-1] 2018-01-29 03:50:24:
pid 27600: LOG: authentication timeout
Jan 29 03:50:24 servername pgpool[10344]: [10114-1] 2018-01-29 03:50:24:
pid 10344: LOG: authentication timeout
Jan 29 03:50:25 servername pgpool[27152]: [10148-1] 2018-01-29 03:50:25:
pid 27152: LOG: authentication timeout
Jan 29 03:50:25 servername pgpool[29558]: [4773-1] 2018-01-29 03:50:25: pid
29558: LOG: authentication timeout
Jan 29 03:50:33 servername pgpool[27262]: [10152-1] 2018-01-29 03:50:33:
pid 27262: LOG: authentication timeout
Jan 29 03:50:36 servername pgpool[27122]: [10146-1] 2018-01-29 03:50:36:
pid 27122: LOG: authentication timeout
Jan 29 03:50:43 servername pgpool[27498]: [10158-1] 2018-01-29 03:50:43:
pid 27498: LOG: authentication timeout
Jan 29 03:50:45 servername pgpool[9814]: [10106-1] 2018-01-29 03:50:45: pid
9814: LOG: authentication timeout
Jan 29 03:50:48 servername pgpool[27471]: [10156-1] 2018-01-29 03:50:48:
pid 27471: LOG: authentication timeout
I have pulled the logs before and after the issue
Jan 29 03:47:50 servername pgpool[7394]: [135179-1] 2018-01-29 03:47:50:
pid 7394: LOG: new IPC connection received
Jan 29 03:47:50 servername pgpool[7766]: [405382-1] 2018-01-29 03:47:50:
pid 7766: LOG: PCP process with pid: 14025 exit with SUCCESS.
Jan 29 03:47:50 servername pgpool[7766]: [405383-1] 2018-01-29 03:47:50:
pid 7766: LOG: PCP process with pid: 14025 exits with status 0
Jan 29 03:49:25 servername pgpool[7766]: [405384-1] 2018-01-29 03:49:25:
pid 7766: LOG: forked new pcp worker, pid=17102 socket=8
Jan 29 03:49:25 servername pgpool[7394]: [135180-1] 2018-01-29 03:49:25:
pid 7394: LOG: new IPC connection received
Jan 29 03:49:25 servername pgpool[7766]: [405385-1] 2018-01-29 03:49:25:
pid 7766: LOG: PCP process with pid: 17102 exit with SUCCESS.
Jan 29 03:49:25 servername pgpool[7766]: [405386-1] 2018-01-29 03:49:25:
pid 7766: LOG: PCP process with pid: 17102 exits with status 0
*Jan 29 03:50:12 servername pgpool[5306]: [10130-1] 2018-01-29 03:50:12:
pid 5306: LOG: authentication timeout*
Jan 29 03:50:12 servername pgpool[7393]: [10163-1] 2018-01-29 03:50:12: pid
7393: LOG: child process with pid: 5306 exits with status 256
Jan 29 03:50:12 servername pgpool[7393]: [10164-1] 2018-01-29 03:50:12: pid
7393: LOG: fork a new child process with pid: 20718
*Jan 29 03:50:14 servername pgpool[26905]: [10142-1] 2018-01-29 03:50:14:
pid 26905: LOG: authentication timeout*
Jan 29 03:50:14 servername pgpool[7393]: [10165-1] 2018-01-29 03:50:14: pid
7393: LOG: child process with pid: 26905 exits with status 256
Jan 29 03:50:14 servername pgpool[7393]: [10166-1] 2018-01-29 03:50:14: pid
7393: LOG: fork a new child process with pid: 21350
Jan 29 03:50:16 servername pgpool[7766]: [405387-1] 2018-01-29 03:50:16:
pid 7766: LOG: forked new pcp worker, pid=21647 socket=8
Jan 29 03:50:16 servername pgpool[7394]: [135181-1] 2018-01-29 03:50:16:
pid 7394: LOG: new IPC connection received
Jan 29 03:50:16 servername pgpool[7766]: [405388-1] 2018-01-29 03:50:16:
pid 7766: LOG: PCP process with pid: 21647 exit with SUCCESS.
Jan 29 03:50:16 servername pgpool[7766]: [405389-1] 2018-01-29 03:50:16:
pid 7766: LOG: PCP process with pid: 21647 exits with status 0
*Jan 29 03:50:24 servername pgpool[27600]: [10162-1] 2018-01-29 03:50:24:
pid 27600: LOG: authentication timeout*
Jan 29 03:50:24 servername pgpool[7393]: [10167-1] 2018-01-29 03:50:24: pid
7393: LOG: child process with pid: 27600 exits with status 256
Jan 29 03:50:24 servername pgpool[7393]: [10168-1] 2018-01-29 03:50:24: pid
7393: LOG: fork a new child process with pid: 22191
*Jan 29 03:50:24 servername pgpool[10344]: [10114-1] 2018-01-29 03:50:24:
pid 10344: LOG: authentication timeout*
Jan 29 03:50:24 servername pgpool[7393]: [10169-1] 2018-01-29 03:50:24: pid
7393: LOG: child process with pid: 10344 exits with status 256
Jan 29 03:50:24 servername pgpool[7393]: [10170-1] 2018-01-29 03:50:24: pid
7393: LOG: fork a new child process with pid: 22206
*Jan 29 03:50:25 servername pgpool[27152]: [10148-1] 2018-01-29 03:50:25:
pid 27152: LOG: authentication timeout*
Jan 29 03:50:25 servername pgpool[7393]: [10171-1] 2018-01-29 03:50:25: pid
7393: LOG: child process with pid: 27152 exits with status 256
Jan 29 03:50:25 servername pgpool[7393]: [10172-1] 2018-01-29 03:50:25: pid
7393: LOG: fork a new child process with pid: 22335
*Jan 29 03:50:25 servername pgpool[29558]: [4773-1] 2018-01-29 03:50:25:
pid 29558: LOG: authentication timeout*
Jan 29 03:50:25 servername pgpool[7393]: [10173-1] 2018-01-29 03:50:25: pid
7393: LOG: child process with pid: 29558 exits with status 256
Jan 29 03:50:25 servername pgpool[7393]: [10174-1] 2018-01-29 03:50:25: pid
7393: LOG: fork a new child process with pid: 22355
*Jan 29 03:50:33 servername pgpool[27262]: [10152-1] 2018-01-29 03:50:33:
pid 27262: LOG: authentication timeout*
Jan 29 03:50:33 servername pgpool[7393]: [10175-1] 2018-01-29 03:50:33: pid
7393: LOG: child process with pid: 27262 exits with status 256
Jan 29 03:50:33 servername pgpool[7393]: [10176-1] 2018-01-29 03:50:33: pid
7393: LOG: fork a new child process with pid: 22844
*Jan 29 03:50:36 servername pgpool[27122]: [10146-1] 2018-01-29 03:50:36:
pid 27122: LOG: authentication timeout*
Jan 29 03:50:36 servername pgpool[7393]: [10177-1] 2018-01-29 03:50:36: pid
7393: LOG: child process with pid: 27122 exits with status 256
Jan 29 03:50:36 servername pgpool[7393]: [10178-1] 2018-01-29 03:50:36: pid
7393: LOG: fork a new child process with pid: 23059
*Jan 29 03:50:43 servername pgpool[27498]: [10158-1] 2018-01-29 03:50:43:
pid 27498: LOG: authentication timeout*
Jan 29 03:50:43 servername pgpool[7393]: [10179-1] 2018-01-29 03:50:43: pid
7393: LOG: child process with pid: 27498 exits with status 256
Jan 29 03:50:43 servername pgpool[7393]: [10180-1] 2018-01-29 03:50:43: pid
7393: LOG: fork a new child process with pid: 23562
*Jan 29 03:50:45 servername pgpool[9814]: [10106-1] 2018-01-29 03:50:45:
pid 9814: LOG: authentication timeout*
Jan 29 03:50:45 servername pgpool[7393]: [10181-1] 2018-01-29 03:50:45: pid
7393: LOG: child process with pid: 9814 exits with status 256
Jan 29 03:50:45 servername pgpool[7393]: [10182-1] 2018-01-29 03:50:45: pid
7393: LOG: fork a new child process with pid: 23932
*Jan 29 03:50:48 servername pgpool[27471]: [10156-1] 2018-01-29 03:50:48:
pid 27471: LOG: authentication timeout*
Jan 29 03:50:48 servername pgpool[7393]: [10183-1] 2018-01-29 03:50:48: pid
7393: LOG: child process with pid: 27471 exits with status 256
Jan 29 03:50:48 servername pgpool[7393]: [10184-1] 2018-01-29 03:50:48: pid
7393: LOG: fork a new child process with pid: 24037
Jan 29 03:51:16 servername pgpool[7766]: [405390-1] 2018-01-29 03:51:16:
pid 7766: LOG: forked new pcp worker, pid=26605 socket=8
Jan 29 03:51:16 servername pgpool[7394]: [135182-1] 2018-01-29 03:51:16:
pid 7394: LOG: new IPC connection received
Jan 29 03:51:16 servername pgpool[7766]: [405391-1] 2018-01-29 03:51:16:
pid 7766: LOG: PCP process with pid: 26605 exit with SUCCESS.
Jan 29 03:51:16 servername pgpool[7766]: [405392-1] 2018-01-29 03:51:16:
pid 7766: LOG: PCP process with pid: 26605 exits with status 0
Jan 29 03:52:13 servername pgpool[7766]: [405393-1] 2018-01-29 03:52:13:
pid 7766: LOG: forked new pcp worker, pid=31533 socket=8
Jan 29 03:52:13 servername pgpool[7394]: [135183-1] 2018-01-29 03:52:13:
pid 7394: LOG: new IPC connection received
Jan 29 03:52:13 servername pgpool[7766]: [405394-1] 2018-01-29 03:52:13:
pid 7766: LOG: PCP process with pid: 31533 exit with SUCCESS.
Jan 29 03:52:13 servername pgpool[7766]: [405395-1] 2018-01-29 03:52:13:
pid 7766: LOG: PCP process with pid: 31533 exits with status 0
Jan 29 03:53:17 servername pgpool[7766]: [405396-1] 2018-01-29 03:53:17:
pid 7766: LOG: forked new pcp worker, pid=4556 socket=8
Jan 29 03:53:17 servername pgpool[7394]: [135184-1] 2018-01-29 03:53:17:
pid 7394: LOG: new IPC connection received
Jan 29 03:53:17 servername pgpool[7766]: [405397-1] 2018-01-29 03:53:17:
pid 7766: LOG: PCP process with pid: 4556 exit with SUCCESS.
Jan 29 03:53:17 servername pgpool[7766]: [405398-1] 2018-01-29 03:53:17:
pid 7766: LOG: PCP process with pid: 4556 exits with status 0
Jan 29 03:54:39 servername pgpool[7766]: [405399-1] 2018-01-29 03:54:39:
pid 7766: LOG: forked new pcp worker, pid=11209 socket=8
Jan 29 03:54:39 servername pgpool[7394]: [135185-1] 2018-01-29 03:54:39:
pid 7394: LOG: new IPC connection received
Jan 29 03:54:39 servername pgpool[7766]: [405400-1] 2018-01-29 03:54:39:
pid 7766: LOG: PCP process with pid: 11209 exit with SUCCESS.
Jan 29 03:54:39 servername pgpool[7766]: [405401-1] 2018-01-29 03:54:39:
pid 7766: LOG: PCP process with pid: 11209 exits with status 0
Jan 29 03:54:53 servername pgpool[7766]: [405402-1] 2018-01-29 03:54:53:
pid 7766: LOG: forked new pcp worker, pid=12916 socket=8
Please find attached pgpool.conf.
Let me know if any more information is needed.
Thanks
Pankaj Joshi
On Thu, Jan 25, 2018 at 8:09 PM, Muhammad Usama <m.usama at gmail.com> wrote:
> Hi Joshi,
>
> Does this "authentication timeout" happens randomly or it starts
> happening after some watchdog event/pcp command.
> Also please share the pgpool.conf file you are using.
>
> Thanks
> Best Regards
> Muhammad Usama
>
>
>
> On Tue, Jan 16, 2018 at 2:55 PM, Pankaj Joshi <pankajjo02 at gmail.com>
> wrote:
>
>> Hello Team ,
>>
>> I am using pgpool-II version 3.6.5 (subaruboshi) with postgres 9.6.4 as
>> backend , our setup uses watchdog as well and have 2 nodes in which the
>> postgres runs . recently
>> have started to see lot of authentication timeout in pgpool logs .
>>
>> like
>>
>> Jan 16 00:05:20 servername pgpool[23096]: [10091-1] 2018-01-16 00:05:20:
>> pid 23096: LOG: authentication timeout
>> Jan 16 00:05:20 servername pgpool[7393]: [10117-1] 2018-01-16 00:05:20:
>> pid 7393: LOG: child process with pid: 23096 exits with status 256
>> Jan 16 00:05:20 servername pgpool[7393]: [10118-1] 2018-01-16 00:05:20:
>> pid 7393: LOG: fork a new child process with pid: 3865
>> Jan 16 00:05:20 servername pgpool[21532]: [9711-1] 2018-01-16 00:05:20:
>> pid 21532: LOG: authentication timeout
>> Jan 16 00:05:20 servername pgpool[7393]: [10119-1] 2018-01-16 00:05:20:
>> pid 7393: LOG: child process with pid: 21532 exits with status 256
>> Jan 16 00:05:20 servername pgpool[7393]: [10120-1] 2018-01-16 00:05:20:
>> pid 7393: LOG: fork a new child process with pid: 3866
>> Jan 16 00:05:21 servername pgpool[10125]: [10108-1] 2018-01-16 00:05:21:
>> pid 10125: LOG: authentication timeout
>> Jan 16 00:05:21 servername pgpool[7393]: [10121-1] 2018-01-16 00:05:21:
>> pid 7393: LOG: child process with pid: 10125 exits with status 256
>> Jan 16 00:05:21 servername pgpool[7393]: [10122-1] 2018-01-16 00:05:21:
>> pid 7393: LOG: fork a new child process with pid: 3965
>> Jan 16 00:05:22 servername pgpool[7782]: [10013-1] 2018-01-16 00:05:22:
>> pid 7782: LOG: authentication timeout
>> Jan 16 00:05:22 servername pgpool[7393]: [10123-1] 2018-01-16 00:05:22:
>> pid 7393: LOG: child process with pid: 7782 exits with status 256
>> Jan 16 00:05:22 servername pgpool[7393]: [10124-1] 2018-01-16 00:05:22:
>> pid 7393: LOG: fork a new child process with pid: 4033
>> Jan 16 00:05:27 servername pgpool[7626]: [10053-1] 2018-01-16 00:05:27:
>> pid 7626: LOG: authentication timeout
>> Jan 16 00:05:27 servername pgpool[7393]: [10125-1] 2018-01-16 00:05:27:
>> pid 7393: LOG: child process with pid: 7626 exits with status 256
>> Jan 16 00:05:27 servername pgpool[7393]: [10126-1] 2018-01-16 00:05:27:
>> pid 7393: LOG: fork a new child process with pid: 4383
>> Jan 16 00:05:37 servername pgpool[30028]: [10009-1] 2018-01-16 00:05:37:
>> pid 30028: LOG: authentication timeout
>> Jan 16 00:05:37 servername pgpool[7393]: [10127-1] 2018-01-16 00:05:37:
>> pid 7393: LOG: child process with pid: 30028 exits with status 256
>> Jan 16 00:05:37 servername pgpool[7393]: [10128-1] 2018-01-16 00:05:37:
>> pid 7393: LOG: fork a new child process with pid: 5059
>> Jan 16 00:05:41 servername pgpool[23825]: [10007-1] 2018-01-16 00:05:41:
>> pid 23825: LOG: authentication timeout
>> Jan 16 00:05:41 servername pgpool[7393]: [10129-1] 2018-01-16 00:05:41:
>> pid 7393: LOG: child process with pid: 23825 exits with status 256
>> Jan 16 00:05:41 servername pgpool[7393]: [10130-1] 2018-01-16 00:05:41:
>> pid 7393: LOG: fork a new child process with pid: 5306
>> Jan 16 00:05:41 servername pgpool[9805]: [10104-1] 2018-01-16 00:05:41:
>> pid 9805: LOG: authentication timeout
>> Jan 16 00:05:41 servername pgpool[7393]: [10131-1] 2018-01-16 00:05:41:
>> pid 7393: LOG: child process with pid: 9805 exits with status 256
>>
>>
>> when I check postgres logs I do not see any logs pertaining to the
>> connection failures or timeouts.
>>
>> This pattern mostly goes till next 2-3 mins and then becomes normal, the
>> occurrence is random .
>>
>> I am not sure if its pgpool issue or postgres is having some issues .
>>
>> let me know the information which I shoud be providing to be able to
>> identify /fix it.
>>
>>
>> Thanks
>> Pankaj Joshi
>>
>> _______________________________________________
>> 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/20180129/18736761/attachment-0001.html>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: pgpool.conf
Type: application/octet-stream
Size: 40357 bytes
Desc: not available
URL: <http://www.sraoss.jp/pipermail/pgpool-general/attachments/20180129/18736761/attachment-0001.obj>
More information about the pgpool-general
mailing list