View Issue Details

IDProjectCategoryView StatusLast Update
0000289Pgpool-IIBugpublic2017-04-13 19:27
ReportergdeciccoAssigned ToMuhammad Usama 
PrioritynormalSeveritymajorReproducibilityalways
Status resolvedResolutionfixed 
PlatformLinuxOSDebian X64OS Versionstretch
Product Version3.6.1 
Target VersionFixed in Version 
Summary0000289: Inconsistent backend state
DescriptionSimilar problem reported on issue 0000218 (http://www.pgpool.net/mantisbt/view.php?id=218).
The same inconsistent state can be reached when a pgpool instance could not communicate with the others.


0) This was the orignal configuraton:
master/slave streaming replication

pgppool master (alpha) ---+ +---db replica1 (xray)
                             | |
pgpool standby1 (bravo) ---+----+---db replica2 (yankee)
                             | |
pgpool standby2 (charlie) ---+ +---db master (zulu)


1) After a network partitioning charlie remains disconnected from the other pgpool instances but can access the databases without any problem:


pgppool master (alpha) ---+ +---db replica1 (xray)
                             | |
pgpool standby1 (bravo) ---+----+---db replica2 (yankee)
                                  |
                                  |
pgpool standby2 (charlie) ---+----+---db master (zulu)



charlie now thinks to be the new master (but without quorum). No problem at this time.

2) Now suppose zulu becomes unreachable form alpha and bravo (but not from charlie). The pgpool master (alpha) will start the failover solving the problem:



pgppool master (alpha) ---+ +---db new master (xray)----+
                              | | |
pgpool standby1 (bravo) ---+----+---db replica2 (yankee)-----+
                                   X |
                                                                |
                                   +----------------------------+
                                   |
pgpool standby2* (charlie) ---+----+---db master (zulu)

alpha and charlie have now this vision of the backend:

0 | zulu | down | standby |
1 | xray | up | primary |
2 | yankee | up | standby |

while charlie has this one:

0 | zulu | up | primary |
1 | xray | up | standby |
2 | yankee | down | standby |

charlie sees yankee down because the followmaster script run by alpha shut it down while charlie was not connected with the other pgpool instances (this is still an expected behaviour).

3) Now when charlie returns reachable by alpha and bravo, it recognizes the new master (alpha).

(zulu still can't communicate with alpha and bravo)
pgppool master (alpha) ---+ +---db new master (xray)----+
                              | | |
pgpool standby1 (bravo) ---+----+---db replica2 (yankee)-----+
                              | X |
                              | |
                              | +----------------------------+
                              | |
pgpool standby2 (charlie) ---+----+---db master (zulu)


Now what I was expecting was that charlie would query the master for the backend state (as it would have done in case of a restart [solved issue 0000218])

Actually charlie keeps the old vision of the databases' state, and the pgpool system reaches a dangreous inconsistent state.

Restarting charlie's pgpool process fixes the problem (as solved issue 218 explains), because charlie queries the master for backend status.

I have attached charlie's log during network reconnection (charlie-reconnect.log) and during restart (charlie-restart.log)
as you can see during the restart everything works as expected:



Feb 24 15:46:40 debian-base pgpool[4007]: 2017-02-24 15:46:40: pid 4008: LOG: get data request from local pgpool-II node received on IPC interface is forwarded to master watchdog node "alpha:5432 Linux debian-base"
Feb 24 15:46:40 debian-base pgpool[4007]: 2017-02-24 15:46:40: pid 4008: DETAIL: waiting for the reply...
Feb 24 15:46:40 debian-base pgpool[4007]: 2017-02-24 15:46:40: pid 4007: LOG: master watchdog node "alpha:5432 Linux debian-base" returned status for 3 backend nodes
Feb 24 15:46:40 debian-base pgpool[4007]: 2017-02-24 15:46:40: pid 4007: LOG: primary node on master watchdog node "alpha:5432 Linux debian-base" is 1
Feb 24 15:46:40 debian-base pgpool[4007]: 2017-02-24 15:46:40: pid 4007: LOG: backend status from "alpha:5432 Linux debian-base" backend:0 is set to down status



The desirable behaviour would be the following: when charlie detects that it is no longer the master, it should query the actual master for the backend state, hence behaving as if a restart had happened.
Steps To Reproducestep 1)
on charlie:
$ iptables -A INPUT -s alpha -j DROP
$ iptables -A INPUT -s bravo -j DROP

on alpha and bravo:
$ iptables -A INPUT -s charlie -j DROP


step 2)
on zulu:
$ iptables -A INPUT -s alpha -j DROP
$ iptables -A INPUT -s bravo -j DROP


setp 3)
on charlie:
$ iptables -D INPUT 1
$ iptables -D INPUT 1
(if u have only those 2 line in your ip tables)
Additional InformationCHARLIE-RECONNECT.LOG:

Feb 24 15:39:11 debian-base pgpool[3862]: [13-1] 2017-02-24 15:39:11: pid 3862: LOG: informing the node status change to watchdog
Feb 24 15:39:11 debian-base pgpool[3862]: [13-2] 2017-02-24 15:39:11: pid 3862: DETAIL: node id :1 status = "NODE ALIVE" message:"Heartbeat signal found"
Feb 24 15:39:11 debian-base pgpool[3862]: [14-1] 2017-02-24 15:39:11: pid 3862: LOG: informing the node status change to watchdog
Feb 24 15:39:11 debian-base pgpool[3862]: [14-2] 2017-02-24 15:39:11: pid 3862: DETAIL: node id :2 status = "NODE ALIVE" message:"Heartbeat signal found"
Feb 24 15:39:11 debian-base pgpool[3860]: 2017-02-24 15:39:11: pid 3862: LOG: informing the node status change to watchdog
Feb 24 15:39:11 debian-base pgpool[3860]: 2017-02-24 15:39:11: pid 3862: DETAIL: node id :1 status = "NODE ALIVE" message:"Heartbeat signal found"
Feb 24 15:39:11 debian-base pgpool[3860]: 2017-02-24 15:39:11: pid 3862: LOG: informing the node status change to watchdog
Feb 24 15:39:11 debian-base pgpool[3860]: 2017-02-24 15:39:11: pid 3862: DETAIL: node id :2 status = "NODE ALIVE" message:"Heartbeat signal found"
Feb 24 15:39:11 debian-base pgpool[3861]: [58-1] 2017-02-24 15:39:11: pid 3861: LOG: new IPC connection received
Feb 24 15:39:11 debian-base pgpool[3861]: [59-1] 2017-02-24 15:39:11: pid 3861: LOG: new IPC connection received
Feb 24 15:39:11 debian-base pgpool[3861]: [60-1] 2017-02-24 15:39:11: pid 3861: LOG: received node status change ipc message
Feb 24 15:39:11 debian-base pgpool[3861]: [60-2] 2017-02-24 15:39:11: pid 3861: DETAIL: Heartbeat signal found
Feb 24 15:39:11 debian-base pgpool[3861]: [61-1] 2017-02-24 15:39:11: pid 3861: LOG: received node status change ipc message
Feb 24 15:39:11 debian-base pgpool[3861]: [61-2] 2017-02-24 15:39:11: pid 3861: DETAIL: Heartbeat signal found
Feb 24 15:39:11 debian-base pgpool[3860]: 2017-02-24 15:39:11: pid 3861: LOG: new IPC connection received
Feb 24 15:39:11 debian-base pgpool[3860]: 2017-02-24 15:39:11: pid 3861: LOG: new IPC connection received
Feb 24 15:39:11 debian-base pgpool[3860]: 2017-02-24 15:39:11: pid 3861: LOG: received node status change ipc message
Feb 24 15:39:11 debian-base pgpool[3860]: 2017-02-24 15:39:11: pid 3861: DETAIL: Heartbeat signal found
Feb 24 15:39:11 debian-base pgpool[3860]: 2017-02-24 15:39:11: pid 3861: LOG: received node status change ipc message
Feb 24 15:39:11 debian-base pgpool[3860]: 2017-02-24 15:39:11: pid 3861: DETAIL: Heartbeat signal found

Feb 24 15:39:50 debian-base pgpool[3861]: [62-1] 2017-02-24 15:39:50: pid 3861: LOG: new outbond connection to alpha:9000
Feb 24 15:39:50 debian-base pgpool[3861]: [63-1] 2017-02-24 15:39:50: pid 3861: LOG: new outbond connection to bravo:9000
Feb 24 15:39:50 debian-base pgpool[3860]: 2017-02-24 15:39:50: pid 3861: LOG: new outbond connection to alpha:9000
Feb 24 15:39:50 debian-base pgpool[3860]: 2017-02-24 15:39:50: pid 3861: LOG: new outbond connection to bravo:9000
Feb 24 15:39:50 debian-base pgpool[3861]: [64-1] 2017-02-24 15:39:50: pid 3861: WARNING: "charlie:5432 Linux debian-base" is the coordinator as per our record but "alpha:5432 Linux debian-base" is also announcing as a coordinator
Feb 24 15:39:50 debian-base pgpool[3861]: [64-2] 2017-02-24 15:39:50: pid 3861: DETAIL: re-initializing the cluster
Feb 24 15:39:50 debian-base pgpool[3861]: [65-1] 2017-02-24 15:39:50: pid 3861: LOG: watchdog node state changed from [MASTER] to [JOINING]
Feb 24 15:39:50 debian-base pgpool[3860]: 2017-02-24 15:39:50: pid 3861: WARNING: "charlie:5432 Linux debian-base" is the coordinator as per our record but "alpha:5432 Linux debian-base" is also announcing as a coordinator
Feb 24 15:39:50 debian-base pgpool[3860]: 2017-02-24 15:39:50: pid 3861: DETAIL: re-initializing the cluster
Feb 24 15:39:50 debian-base pgpool[3860]: 2017-02-24 15:39:50: pid 3861: LOG: watchdog node state changed from [MASTER] to [JOINING]
Feb 24 15:39:50 debian-base pgpool[3861]: [66-1] 2017-02-24 15:39:50: pid 3861: LOG: watchdog node state changed from [JOINING] to [INITIALIZING]
Feb 24 15:39:50 debian-base pgpool[3860]: 2017-02-24 15:39:50: pid 3861: LOG: watchdog node state changed from [JOINING] to [INITIALIZING]
Feb 24 15:39:51 debian-base pgpool[3861]: [67-1] 2017-02-24 15:39:51: pid 3861: LOG: watchdog node state changed from [INITIALIZING] to [STANDBY]
Feb 24 15:39:51 debian-base pgpool[3861]: [68-1] 2017-02-24 15:39:51: pid 3861: LOG: successfully joined the watchdog cluster as standby node
Feb 24 15:39:51 debian-base pgpool[3861]: [68-2] 2017-02-24 15:39:51: pid 3861: DETAIL: our join coordinator request is accepted by cluster leader node "alpha:5432 Linux debian-base"
Feb 24 15:39:51 debian-base pgpool[3860]: 2017-02-24 15:39:51: pid 3861: LOG: watchdog node state changed from [INITIALIZING] to [STANDBY]
Feb 24 15:39:51 debian-base pgpool[3860]: 2017-02-24 15:39:51: pid 3861: LOG: successfully joined the watchdog cluster as standby node
Feb 24 15:39:51 debian-base pgpool[3860]: 2017-02-24 15:39:51: pid 3861: DETAIL: our join coordinator request is accepted by cluster leader node "alpha:5432 Linux debian-base"
Feb 24 15:39:56 debian-base pgpool[3861]: [69-1] 2017-02-24 15:39:56: pid 3861: LOG: new watchdog node connection is received from "bravo:51381"
Feb 24 15:39:56 debian-base pgpool[3861]: [70-1] 2017-02-24 15:39:56: pid 3861: LOG: new node joined the cluster hostname:"bravo" port:9000 pgpool_port:5432
Feb 24 15:39:56 debian-base pgpool[3860]: 2017-02-24 15:39:56: pid 3861: LOG: new watchdog node connection is received from "bravo:51381"
Feb 24 15:39:56 debian-base pgpool[3860]: 2017-02-24 15:39:56: pid 3861: LOG: new node joined the cluster hostname:"bravo" port:9000 pgpool_port:5432
Feb 24 15:39:57 debian-base pgpool[3861]: [71-1] 2017-02-24 15:39:57: pid 3861: LOG: new watchdog node connection is received from "alpha:43464"
Feb 24 15:39:57 debian-base pgpool[3861]: [72-1] 2017-02-24 15:39:57: pid 3861: LOG: new node joined the cluster hostname:"alpha" port:9000 pgpool_port:5432
Feb 24 15:39:57 debian-base pgpool[3860]: 2017-02-24 15:39:57: pid 3861: LOG: new watchdog node connection is received from "alpha:43464"
Feb 24 15:39:57 debian-base pgpool[3860]: 2017-02-24 15:39:57: pid 3861: LOG: new node joined the cluster hostname:"alpha" port:9000 pgpool_port:5432


























CHARLIE_RESTART.LOG:

Feb 24 15:46:39 debian-base pgpool[4007]: [4-1] 2017-02-24 15:46:39: pid 4007: LOG: reading status file: 2 th backend is set to down status
Feb 24 15:46:39 debian-base pgpool[4007]: 2017-02-24 15:46:39: pid 4007: LOG: reading status file: 2 th backend is set to down status
Feb 24 15:46:39 debian-base pgpool[4007]: [5-1] 2017-02-24 15:46:39: pid 4007: LOG: waiting for watchdog to initialize
Feb 24 15:46:39 debian-base pgpool[4007]: 2017-02-24 15:46:39: pid 4007: LOG: waiting for watchdog to initialize
Feb 24 15:46:39 debian-base pgpool[4008]: [5-1] 2017-02-24 15:46:39: pid 4008: LOG: setting the local watchdog node name to "charlie:5432 Linux debian-base"
Feb 24 15:46:39 debian-base pgpool[4007]: 2017-02-24 15:46:39: pid 4008: LOG: setting the local watchdog node name to "charlie:5432 Linux debian-base"
Feb 24 15:46:39 debian-base pgpool[4008]: [6-1] 2017-02-24 15:46:39: pid 4008: LOG: watchdog cluster is configured with 2 remote nodes
Feb 24 15:46:39 debian-base pgpool[4007]: 2017-02-24 15:46:39: pid 4008: LOG: watchdog cluster is configured with 2 remote nodes
Feb 24 15:46:39 debian-base pgpool[4008]: [7-1] 2017-02-24 15:46:39: pid 4008: LOG: watchdog remote node:0 on alpha:9000
Feb 24 15:46:39 debian-base pgpool[4007]: 2017-02-24 15:46:39: pid 4008: LOG: watchdog remote node:0 on alpha:9000
Feb 24 15:46:39 debian-base pgpool[4008]: [8-1] 2017-02-24 15:46:39: pid 4008: LOG: watchdog remote node:1 on bravo:9000
Feb 24 15:46:39 debian-base pgpool[4007]: 2017-02-24 15:46:39: pid 4008: LOG: watchdog remote node:1 on bravo:9000
Feb 24 15:46:39 debian-base pgpool[4008]: [9-1] 2017-02-24 15:46:39: pid 4008: LOG: interface monitoring is disabled in watchdog
Feb 24 15:46:39 debian-base pgpool[4007]: 2017-02-24 15:46:39: pid 4008: LOG: interface monitoring is disabled in watchdog
Feb 24 15:46:39 debian-base pgpool[4008]: [10-1] 2017-02-24 15:46:39: pid 4008: LOG: watchdog node state changed from [DEAD] to [LOADING]
Feb 24 15:46:39 debian-base pgpool[4007]: 2017-02-24 15:46:39: pid 4008: LOG: watchdog node state changed from [DEAD] to [LOADING]
Feb 24 15:46:39 debian-base pgpool[4008]: [11-1] 2017-02-24 15:46:39: pid 4008: LOG: new outbond connection to alpha:9000
Feb 24 15:46:39 debian-base pgpool[4007]: 2017-02-24 15:46:39: pid 4008: LOG: new outbond connection to alpha:9000
Feb 24 15:46:39 debian-base pgpool[4008]: [12-1] 2017-02-24 15:46:39: pid 4008: LOG: new outbond connection to bravo:9000
Feb 24 15:46:39 debian-base pgpool[4007]: 2017-02-24 15:46:39: pid 4008: LOG: new outbond connection to bravo:9000
Feb 24 15:46:39 debian-base pgpool[4008]: [13-1] 2017-02-24 15:46:39: pid 4008: LOG: new watchdog node connection is received from "alpha:60105"
Feb 24 15:46:39 debian-base pgpool[4008]: [14-1] 2017-02-24 15:46:39: pid 4008: LOG: watchdog node state changed from [LOADING] to [INITIALIZING]
Feb 24 15:46:39 debian-base pgpool[4008]: [15-1] 2017-02-24 15:46:39: pid 4008: LOG: new watchdog node connection is received from "bravo:3511"
Feb 24 15:46:39 debian-base pgpool[4008]: [16-1] 2017-02-24 15:46:39: pid 4008: LOG: new node joined the cluster hostname:"alpha" port:9000 pgpool_port:5432
Feb 24 15:46:39 debian-base pgpool[4007]: 2017-02-24 15:46:39: pid 4008: LOG: new watchdog node connection is received from "alpha:60105"
Feb 24 15:46:39 debian-base pgpool[4007]: 2017-02-24 15:46:39: pid 4008: LOG: watchdog node state changed from [LOADING] to [INITIALIZING]
Feb 24 15:46:39 debian-base pgpool[4007]: 2017-02-24 15:46:39: pid 4008: LOG: new watchdog node connection is received from "bravo:3511"
Feb 24 15:46:39 debian-base pgpool[4007]: 2017-02-24 15:46:39: pid 4008: LOG: new node joined the cluster hostname:"alpha" port:9000 pgpool_port:5432
Feb 24 15:46:39 debian-base pgpool[4008]: [17-1] 2017-02-24 15:46:39: pid 4008: LOG: new node joined the cluster hostname:"bravo" port:9000 pgpool_port:5432
Feb 24 15:46:39 debian-base pgpool[4007]: 2017-02-24 15:46:39: pid 4008: LOG: new node joined the cluster hostname:"bravo" port:9000 pgpool_port:5432
Feb 24 15:46:40 debian-base pgpool[4008]: [18-1] 2017-02-24 15:46:40: pid 4008: LOG: watchdog node state changed from [INITIALIZING] to [STANDBY]
Feb 24 15:46:40 debian-base pgpool[4007]: [6-1] 2017-02-24 15:46:40: pid 4007: LOG: watchdog process is initialized
Feb 24 15:46:40 debian-base pgpool[4008]: [19-1] 2017-02-24 15:46:40: pid 4008: LOG: successfully joined the watchdog cluster as standby node
Feb 24 15:46:40 debian-base pgpool[4008]: [19-2] 2017-02-24 15:46:40: pid 4008: DETAIL: our join coordinator request is accepted by cluster leader node "alpha:5432 Linux debian-base"
Feb 24 15:46:40 debian-base pgpool[4008]: [20-1] 2017-02-24 15:46:40: pid 4008: LOG: new IPC connection received
Feb 24 15:46:40 debian-base pgpool[4008]: [21-1] 2017-02-24 15:46:40: pid 4008: LOG: received the get data request from local pgpool-II on IPC interface
Feb 24 15:46:40 debian-base pgpool[4008]: [22-1] 2017-02-24 15:46:40: pid 4008: LOG: get data request from local pgpool-II node received on IPC interface is forwarded to master watchdog node "alpha:5432 Linux debian-base"
Feb 24 15:46:40 debian-base pgpool[4008]: [22-2] 2017-02-24 15:46:40: pid 4008: DETAIL: waiting for the reply...
Feb 24 15:46:40 debian-base pgpool[4007]: [7-1] 2017-02-24 15:46:40: pid 4007: LOG: master watchdog node "alpha:5432 Linux debian-base" returned status for 3 backend nodes
Feb 24 15:46:40 debian-base pgpool[4007]: [8-1] 2017-02-24 15:46:40: pid 4007: LOG: primary node on master watchdog node "alpha:5432 Linux debian-base" is 1
Feb 24 15:46:40 debian-base pgpool[4007]: [9-1] 2017-02-24 15:46:40: pid 4007: LOG: backend status from "alpha:5432 Linux debian-base" backend:0 is set to down status
Feb 24 15:46:40 debian-base pgpool[4007]: [10-1] 2017-02-24 15:46:40: pid 4007: LOG: Setting up socket for 0.0.0.0:5432
Feb 24 15:46:40 debian-base pgpool[4007]: [11-1] 2017-02-24 15:46:40: pid 4007: LOG: Setting up socket for :::5432
Feb 24 15:46:40 debian-base pgpool[4007]: [12-1] 2017-02-24 15:46:40: pid 4007: LOG: pgpool-II successfully started. version 3.6.1 (subaruboshi)
Feb 24 15:46:40 debian-base pgpool[4008]: [23-1] 2017-02-24 15:46:40: pid 4008: LOG: new IPC connection received
Feb 24 15:46:40 debian-base pgpool[4009]: [7-1] 2017-02-24 15:46:40: pid 4009: LOG: 3 watchdog nodes are configured for lifecheck
Feb 24 15:46:40 debian-base pgpool[4009]: [8-1] 2017-02-24 15:46:40: pid 4009: LOG: watchdog nodes ID:0 Name:"charlie:5432 Linux debian-base"
Feb 24 15:46:40 debian-base pgpool[4009]: [8-2] 2017-02-24 15:46:40: pid 4009: DETAIL: Host:"charlie" WD Port:9000 pgpool-II port:5432
Feb 24 15:46:40 debian-base pgpool[4009]: [9-1] 2017-02-24 15:46:40: pid 4009: LOG: watchdog nodes ID:1 Name:"alpha:5432 Linux debian-base"
Feb 24 15:46:40 debian-base pgpool[4009]: [9-2] 2017-02-24 15:46:40: pid 4009: DETAIL: Host:"alpha" WD Port:9000 pgpool-II port:5432
Feb 24 15:46:40 debian-base pgpool[4009]: [10-1] 2017-02-24 15:46:40: pid 4009: LOG: watchdog nodes ID:2 Name:"bravo:5432 Linux debian-base"
Feb 24 15:46:40 debian-base pgpool[4009]: [10-2] 2017-02-24 15:46:40: pid 4009: DETAIL: Host:"bravo" WD Port:9000 pgpool-II port:5432
Feb 24 15:46:40 debian-base pgpool[4007]: 2017-02-24 15:46:40: pid 4008: LOG: watchdog node state changed from [INITIALIZING] to [STANDBY]
Feb 24 15:46:40 debian-base pgpool[4007]: 2017-02-24 15:46:40: pid 4007: LOG: watchdog process is initialized
Feb 24 15:46:40 debian-base pgpool[4007]: 2017-02-24 15:46:40: pid 4008: LOG: successfully joined the watchdog cluster as standby node
Feb 24 15:46:40 debian-base pgpool[4007]: 2017-02-24 15:46:40: pid 4008: DETAIL: our join coordinator request is accepted by cluster leader node "alpha:5432 Linux debian-base"
Feb 24 15:46:40 debian-base pgpool[4007]: 2017-02-24 15:46:40: pid 4008: LOG: new IPC connection received
Feb 24 15:46:40 debian-base pgpool[4007]: 2017-02-24 15:46:40: pid 4008: LOG: received the get data request from local pgpool-II on IPC interface
Feb 24 15:46:40 debian-base pgpool[4007]: 2017-02-24 15:46:40: pid 4008: LOG: get data request from local pgpool-II node received on IPC interface is forwarded to master watchdog node "alpha:5432 Linux debian-base"
Feb 24 15:46:40 debian-base pgpool[4007]: 2017-02-24 15:46:40: pid 4008: DETAIL: waiting for the reply...
Feb 24 15:46:40 debian-base pgpool[4007]: 2017-02-24 15:46:40: pid 4007: LOG: master watchdog node "alpha:5432 Linux debian-base" returned status for 3 backend nodes
Feb 24 15:46:40 debian-base pgpool[4007]: 2017-02-24 15:46:40: pid 4007: LOG: primary node on master watchdog node "alpha:5432 Linux debian-base" is 1
Feb 24 15:46:40 debian-base pgpool[4007]: 2017-02-24 15:46:40: pid 4007: LOG: backend status from "alpha:5432 Linux debian-base" backend:0 is set to down status
Feb 24 15:46:40 debian-base pgpool[4007]: 2017-02-24 15:46:40: pid 4007: LOG: Setting up socket for 0.0.0.0:5432
Feb 24 15:46:40 debian-base pgpool[4007]: 2017-02-24 15:46:40: pid 4007: LOG: Setting up socket for :::5432
Feb 24 15:46:40 debian-base pgpool[4007]: 2017-02-24 15:46:40: pid 4007: LOG: pgpool-II successfully started. version 3.6.1 (subaruboshi)
Feb 24 15:46:40 debian-base pgpool[4007]: 2017-02-24 15:46:40: pid 4008: LOG: new IPC connection received
Feb 24 15:46:40 debian-base pgpool[4007]: 2017-02-24 15:46:40: pid 4009: LOG: 3 watchdog nodes are configured for lifecheck
Feb 24 15:46:40 debian-base pgpool[4007]: 2017-02-24 15:46:40: pid 4009: LOG: watchdog nodes ID:0 Name:"charlie:5432 Linux debian-base"
Feb 24 15:46:40 debian-base pgpool[4007]: 2017-02-24 15:46:40: pid 4009: DETAIL: Host:"charlie" WD Port:9000 pgpool-II port:5432
Feb 24 15:46:40 debian-base pgpool[4007]: 2017-02-24 15:46:40: pid 4009: LOG: watchdog nodes ID:1 Name:"alpha:5432 Linux debian-base"
Feb 24 15:46:40 debian-base pgpool[4007]: 2017-02-24 15:46:40: pid 4009: DETAIL: Host:"alpha" WD Port:9000 pgpool-II port:5432
Feb 24 15:46:40 debian-base pgpool[4007]: 2017-02-24 15:46:40: pid 4009: LOG: watchdog nodes ID:2 Name:"bravo:5432 Linux debian-base"
Feb 24 15:46:40 debian-base pgpool[4007]: 2017-02-24 15:46:40: pid 4009: DETAIL: Host:"bravo" WD Port:9000 pgpool-II port:5432
Feb 24 15:46:41 debian-base pgpool[4045]: [11-1] 2017-02-24 15:46:41: pid 4045: LOG: set SO_REUSEPORT option to the socket
Feb 24 15:46:41 debian-base pgpool[4045]: [12-1] 2017-02-24 15:46:41: pid 4045: LOG: creating socket for sending heartbeat
Feb 24 15:46:41 debian-base pgpool[4045]: [12-2] 2017-02-24 15:46:41: pid 4045: DETAIL: set SO_REUSEPORT
Feb 24 15:46:41 debian-base pgpool[4046]: [11-1] 2017-02-24 15:46:41: pid 4046: LOG: set SO_REUSEPORT option to the socket
Feb 24 15:46:41 debian-base pgpool[4046]: [12-1] 2017-02-24 15:46:41: pid 4046: LOG: creating watchdog heartbeat receive socket.
Feb 24 15:46:41 debian-base pgpool[4046]: [12-2] 2017-02-24 15:46:41: pid 4046: DETAIL: set SO_REUSEPORT
Feb 24 15:46:41 debian-base pgpool[4047]: [11-1] 2017-02-24 15:46:41: pid 4047: LOG: set SO_REUSEPORT option to the socket
Feb 24 15:46:41 debian-base pgpool[4047]: [12-1] 2017-02-24 15:46:41: pid 4047: LOG: creating socket for sending heartbeat
Feb 24 15:46:41 debian-base pgpool[4047]: [12-2] 2017-02-24 15:46:41: pid 4047: DETAIL: set SO_REUSEPORT
Feb 24 15:46:41 debian-base pgpool[4044]: [11-1] 2017-02-24 15:46:41: pid 4044: LOG: set SO_REUSEPORT option to the socket
Feb 24 15:46:41 debian-base pgpool[4044]: [12-1] 2017-02-24 15:46:41: pid 4044: LOG: creating watchdog heartbeat receive socket.
Feb 24 15:46:41 debian-base pgpool[4044]: [12-2] 2017-02-24 15:46:41: pid 4044: DETAIL: set SO_REUSEPORT
Feb 24 15:46:41 debian-base pgpool[4007]: 2017-02-24 15:46:41: pid 4045: LOG: set SO_REUSEPORT option to the socket
Feb 24 15:46:41 debian-base pgpool[4007]: 2017-02-24 15:46:41: pid 4045: LOG: creating socket for sending heartbeat
Feb 24 15:46:41 debian-base pgpool[4007]: 2017-02-24 15:46:41: pid 4045: DETAIL: set SO_REUSEPORT
Feb 24 15:46:41 debian-base pgpool[4007]: 2017-02-24 15:46:41: pid 4046: LOG: set SO_REUSEPORT option to the socket
Feb 24 15:46:41 debian-base pgpool[4007]: 2017-02-24 15:46:41: pid 4046: LOG: creating watchdog heartbeat receive socket.
Feb 24 15:46:41 debian-base pgpool[4007]: 2017-02-24 15:46:41: pid 4046: DETAIL: set SO_REUSEPORT
Feb 24 15:46:41 debian-base pgpool[4007]: 2017-02-24 15:46:41: pid 4047: LOG: set SO_REUSEPORT option to the socket
Feb 24 15:46:41 debian-base pgpool[4007]: 2017-02-24 15:46:41: pid 4047: LOG: creating socket for sending heartbeat
Feb 24 15:46:41 debian-base pgpool[4007]: 2017-02-24 15:46:41: pid 4047: DETAIL: set SO_REUSEPORT
Feb 24 15:46:41 debian-base pgpool[4007]: 2017-02-24 15:46:41: pid 4044: LOG: set SO_REUSEPORT option to the socket
Feb 24 15:46:41 debian-base pgpool[4007]: 2017-02-24 15:46:41: pid 4044: LOG: creating watchdog heartbeat receive socket.
Feb 24 15:46:41 debian-base pgpool[4007]: 2017-02-24 15:46:41: pid 4044: DETAIL: set SO_REUSEPORT
Feb 24 15:48:20 debian-base pgpool[4009]: [11-1] 2017-02-24 15:48:20: pid 4009: LOG: watchdog: lifecheck started
Feb 24 15:48:20 debian-base pgpool[4007]: 2017-02-24 15:48:20: pid 4009: LOG: watchdog: lifecheck started

Tagspgpool, watchdog

Activities

gdecicco

2017-02-25 01:45

reporter  

charlie-reconnect.log (6,320 bytes)

gdecicco

2017-02-25 02:05

reporter  

0.png (14,075 bytes)
0.png (14,075 bytes)

gdecicco

2017-02-25 02:06

reporter  

1.png (14,315 bytes)
1.png (14,315 bytes)

gdecicco

2017-02-25 02:06

reporter  

2.png (15,450 bytes)
2.png (15,450 bytes)

gdecicco

2017-02-25 02:06

reporter  

3.png (15,349 bytes)
3.png (15,349 bytes)

gdecicco

2017-02-25 02:06

reporter  

charlie-restart.log (13,195 bytes)

gdecicco

2017-02-25 02:08

reporter   ~0001365

I've attached the screenshot of the system architecture because submitting the issue, all the indentation were lost

Muhammad Usama

2017-04-13 19:27

developer   ~0001416

I have pushed the fix for this issue in 3.5, 3.6 and Pgpool-II master branches.

https://git.postgresql.org/gitweb/?p=pgpool2.git;a=commitdiff;h=2997b3a40877aa0f04f4acd080126aad8255ed1c

You can verify the fix by building from the source code.

Issue History

Date Modified Username Field Change
2017-02-25 01:45 gdecicco New Issue
2017-02-25 01:45 gdecicco File Added: charlie-reconnect.log
2017-02-25 01:45 gdecicco Tag Attached: pgpool
2017-02-25 01:45 gdecicco Tag Attached: watchdog
2017-02-25 02:05 gdecicco File Added: 0.png
2017-02-25 02:06 gdecicco File Added: 1.png
2017-02-25 02:06 gdecicco File Added: 2.png
2017-02-25 02:06 gdecicco File Added: 3.png
2017-02-25 02:06 gdecicco File Added: charlie-restart.log
2017-02-25 02:08 gdecicco Note Added: 0001365
2017-03-23 09:04 t-ishii Assigned To => Muhammad Usama
2017-03-23 09:04 t-ishii Status new => assigned
2017-03-23 09:04 t-ishii Description Updated View Revisions
2017-03-23 09:04 t-ishii Steps to Reproduce Updated View Revisions
2017-04-13 19:27 Muhammad Usama Status assigned => resolved
2017-04-13 19:27 Muhammad Usama Resolution open => fixed
2017-04-13 19:27 Muhammad Usama Note Added: 0001416