View Issue Details
| ID | Project | Category | View Status | Date Submitted | Last Update |
|---|---|---|---|---|---|
| 0000651 | Pgpool-II | Bug | public | 2020-10-01 19:10 | 2020-11-20 13:27 |
| Reporter | 7667 | Assigned To | t-ishii | ||
| Priority | normal | Severity | major | Reproducibility | random |
| Status | feedback | Resolution | open | ||
| Product Version | 4.1.2 | ||||
| Summary | 0000651: pgpool stops suddenly | ||||
| Description | Hi, We have set the client_idle_limit parameter from 600 to 0 so that pgpool does not kill sessions, but after 15 minutes, PgPool suddenly stopped and did a failover. Can you help us find out the reason for this failover? I share the pgpool logs: Sep 30 10:48:48 xx01 pgpool[1095]: [1127-1] 2020-09-30 10:48:48: pid 1095: LOG: reload config files. Sep 30 10:48:48 xx01 pgpool[1446]: [15-1] 2020-09-30 10:48:48: pid 1446: LOG: reloading config file Sep 30 10:48:48 xx01 pgpool[10055]: [1100-1] 2020-09-30 10:48:48: pid 10055: LOG: reloading config file Sep 30 10:48:48 xx01 pgpool[1445]: [17-1] 2020-09-30 10:48:48: pid 1445: LOG: reloading config file Sep 30 10:50:41 xx01 pgpool[9836]: [589-1] 2020-09-30 10:50:41: pid 9836: ERROR: unable to read data Sep 30 10:50:41 xx01 pgpool[9836]: [589-2] 2020-09-30 10:50:41: pid 9836: DETAIL: child connection forced to terminate due to client_idle_limit:600 is reached Sep 30 10:54:36 xx01 pgpool[9860]: [589-1] 2020-09-30 10:54:36: pid 9860: ERROR: unable to read data Sep 30 10:54:36 xx01 pgpool[9860]: [589-2] 2020-09-30 10:54:36: pid 9860: DETAIL: child connection forced to terminate due to client_idle_limit:600 is reached Sep 30 10:54:36 xx01 pgpool[9798]: [590-1] 2020-09-30 10:54:36: pid 9798: ERROR: unable to read data Sep 30 10:54:36 xx01 pgpool[9798]: [590-2] 2020-09-30 10:54:36: pid 9798: DETAIL: child connection forced to terminate due to client_idle_limit:600 is reached Sep 30 10:54:36 xx01 pgpool[9895]: [591-1] 2020-09-30 10:54:36: pid 9895: ERROR: unable to read data Sep 30 10:54:36 xx01 pgpool[9895]: [591-2] 2020-09-30 10:54:36: pid 9895: DETAIL: child connection forced to terminate due to client_idle_limit:600 is reached Sep 30 10:54:36 xx01 pgpool[10021]: [592-1] 2020-09-30 10:54:36: pid 10021: ERROR: unable to read data Sep 30 10:54:36 xx01 pgpool[10021]: [592-2] 2020-09-30 10:54:36: pid 10021: DETAIL: child connection forced to terminate due to client_idle_limit:600 is reached Sep 30 10:54:36 xx01 pgpool[9849]: [592-1] 2020-09-30 10:54:36: pid 9849: ERROR: unable to read data Sep 30 10:54:36 xx01 pgpool[9849]: [592-2] 2020-09-30 10:54:36: pid 9849: DETAIL: child connection forced to terminate due to client_idle_limit:600 is reached Sep 30 10:56:51 xx01 pgpool[9851]: [589-1] 2020-09-30 10:56:51: pid 9851: ERROR: unable to read data Sep 30 10:56:51 xx01 pgpool[9851]: [589-2] 2020-09-30 10:56:51: pid 9851: DETAIL: child connection forced to terminate due to client_idle_limit:600 is reached Sep 30 10:56:51 xx01 pgpool[2508]: [1111-1] 2020-09-30 10:56:51: pid 2508: ERROR: unable to read data Sep 30 10:56:51 xx01 pgpool[2508]: [1111-2] 2020-09-30 10:56:51: pid 2508: DETAIL: child connection forced to terminate due to client_idle_limit:600 is reached Sep 30 10:57:10 xx01 pgpool[10050]: [590-1] 2020-09-30 10:57:10: pid 10050: ERROR: unable to read data Sep 30 10:57:10 xx01 pgpool[10050]: [590-2] 2020-09-30 10:57:10: pid 10050: DETAIL: child connection forced to terminate due to client_idle_limit:600 is reached Sep 30 10:57:10 xx01 pgpool[9800]: [588-1] 2020-09-30 10:57:10: pid 9800: ERROR: unable to read data Sep 30 10:57:10 xx01 pgpool[9800]: [588-2] 2020-09-30 10:57:10: pid 9800: DETAIL: child connection forced to terminate due to client_idle_limit:600 is reached Sep 30 10:57:10 xx01 pgpool[9819]: [596-1] 2020-09-30 10:57:10: pid 9819: ERROR: unable to read data Sep 30 10:57:10 xx01 pgpool[9819]: [596-2] 2020-09-30 10:57:10: pid 9819: DETAIL: child connection forced to terminate due to client_idle_limit:600 is reached Sep 30 11:03:17 xx01 pgpool[4953]: [1-1] 2020-09-30 11:03:17: pid 4953: LOG: stop request sent to pgpool. waiting for termination... Sep 30 11:03:17 xx01 pgpool[1097]: [390-1] 2020-09-30 11:03:17: pid 1097: LOG: Watchdog is shutting down Sep 30 11:03:17 xx01 pgpool[4954]: [391-1] 2020-09-30 11:03:17: pid 4954: LOG: watchdog: de-escalation started Sep 30 11:03:17 xx01 pgpool[4954]: [392-1] 2020-09-30 11:03:17: pid 4954: LOG: successfully released the delegate IP:"xx" Sep 30 11:03:17 xx01 pgpool[4954]: [392-2] 2020-09-30 11:03:17: pid 4954: DETAIL: 'if_down_cmd' returned with success Sep 30 11:03:35 xx01 pgpool[5024]: [1-1] 2020-09-30 11:03:35: pid 5024: LOG: memory cache initialized Sep 30 11:03:35 xx01 pgpool[5024]: [1-2] 2020-09-30 11:03:35: pid 5024: DETAIL: memcache blocks :64 I share the system logs: Sep 30 11:03:17 xx01 pgpool: quarantine done. shutdown host xx01(5432) Sep 30 11:03:18 xx01 pgpool: .done. Sep 30 11:03:18 xx01 systemd: Stopped Pgpool-II. Sep 30 11:03:35 xx01 systemd: Started Pgpool-II. Regards, | ||||
| Tags | No tags attached. | ||||
|
|
> Sep 30 11:03:17 xx01 pgpool[4953]: [1-1] 2020-09-30 11:03:17: pid 4953: LOG: stop request sent to pgpool. waiting for termination... This message is issued only when "pgpool stop" is executed. I guess someone hit the command. |
|
|
Nobody manually executed the systemctl command. |
|
|
Ok. But it is also possible that "pgpool stop" can be issued without using systemctl. |
|
|
Thank you for your response but the "pgpool stop" command was not executed either. Furthermore the time between stop and start was only 17 seconds, and this time is very short for a manual action. Could pgpool have stopped and started the service for some reason? |
|
|
That's really strange. Is it possible for you to check whether pgpool command was actually executed at the time when you saw "stop request sent to pgpool. waiting for termination..." in the log file by using lastcomm command? |
| Date Modified | Username | Field | Change |
|---|---|---|---|
| 2020-10-01 19:10 | 7667 | New Issue | |
| 2020-10-02 12:06 | t-ishii | Note Added: 0003576 | |
| 2020-10-02 13:11 | t-ishii | Assigned To | => t-ishii |
| 2020-10-02 13:11 | t-ishii | Status | new => feedback |
| 2020-10-03 00:37 | 7667 | Note Added: 0003577 | |
| 2020-10-03 00:37 | 7667 | Status | feedback => assigned |
| 2020-10-03 08:10 | t-ishii | Note Added: 0003578 | |
| 2020-10-29 21:58 | t-ishii | Status | assigned => feedback |
| 2020-11-19 18:32 | 7667 | Note Added: 0003601 | |
| 2020-11-19 18:32 | 7667 | Status | feedback => assigned |
| 2020-11-20 13:26 | t-ishii | Note Added: 0003603 | |
| 2020-11-20 13:27 | t-ishii | Status | assigned => feedback |
