[pgpool-hackers: 3766] 073.pg_terminate_backend sometimes fails
Tatsuo Ishii
ishii at sraoss.co.jp
Mon Aug 3 14:40:25 JST 2020
Hi Usama,
Recently 073.pg_terminate_backend sometimes fails (like 5 of 10).
count_up: 2
count_down: 1
connection count is not matched.
Is this somewhat related to the regression failure?
creating test environment...PostgreSQL major version: 123
Starting set up in streaming replication mode
creating startall and shutdownall
creating failover script
creating database cluster /home/t-ishii/work/Pgpool-II/current/pgpool2/src/test/regression/tests/073.pg_terminate_backend/testdir/data0...done.
update postgresql.conf
creating pgpool_remote_start
creating basebackup.sh
creating recovery.conf
creating database cluster /home/t-ishii/work/Pgpool-II/current/pgpool2/src/test/regression/tests/073.pg_terminate_backend/testdir/data1...done.
update postgresql.conf
creating pgpool_remote_start
creating basebackup.sh
creating recovery.conf
temporarily start data0 cluster to create extensions
temporarily start pgpool-II to create standby nodes
node_id | hostname | port | status | lb_weight | role | select_cnt | load_balance_node | replication_delay | replication_state | replication_sync_state | last_status_change
---------+----------+-------+--------+-----------+---------+------------+-------------------+-------------------+-------------------+------------------------+---------------------
0 | /tmp | 11002 | up | 0.500000 | primary | 0 | true | 0 | | | 2020-08-01 15:34:15
1 | /tmp | 11003 | down | 0.500000 | standby | 0 | false | 0 | | | 2020-08-01 15:34:14
(2 rows)
recovery node 1...pcp_recovery_node -- Command Successful
done.
creating follow master script
node_id | hostname | port | status | lb_weight | role | select_cnt | load_balance_node | replication_delay | replication_state | replication_sync_state | last_status_change
---------+----------+-------+--------+-----------+---------+------------+-------------------+-------------------+-------------------+------------------------+---------------------
0 | /tmp | 11002 | up | 0.500000 | primary | 0 | false | 0 | | | 2020-08-01 15:34:15
1 | /tmp | 11003 | up | 0.500000 | standby | 0 | true | 0 | | | 2020-08-01 15:34:19
(2 rows)
shutdown all
pgpool-II setting for streaming replication mode is done.
To start the whole system, use /home/t-ishii/work/Pgpool-II/current/pgpool2/src/test/regression/tests/073.pg_terminate_backend/testdir/startall.
To shutdown the whole system, use /home/t-ishii/work/Pgpool-II/current/pgpool2/src/test/regression/tests/073.pg_terminate_backend/testdir/shutdownall.
pcp command user name is "t-ishii", password is "t-ishii".
Each PostgreSQL, pgpool-II and pcp port is as follows:
#1 port is 11002
#2 port is 11003
pgpool port is 11000
pcp port is 11001
The info above is in README.port.
done.
waiting for server to start....15620 2020-08-01 15:34:25 JST LOG: starting PostgreSQL 12.3 on x86_64-pc-linux-gnu, compiled by gcc (Ubuntu 7.5.0-3ubuntu1~18.04) 7.5.0, 64-bit
15620 2020-08-01 15:34:25 JST LOG: listening on IPv4 address "0.0.0.0", port 11002
15620 2020-08-01 15:34:25 JST LOG: listening on IPv6 address "::", port 11002
15620 2020-08-01 15:34:25 JST LOG: listening on Unix socket "/tmp/.s.PGSQL.11002"
15620 2020-08-01 15:34:25 JST LOG: redirecting log output to logging collector process
15620 2020-08-01 15:34:25 JST HINT: Future log output will appear in directory "log".
done
server started
waiting for server to start....15633 2020-08-01 15:34:25 JST LOG: starting PostgreSQL 12.3 on x86_64-pc-linux-gnu, compiled by gcc (Ubuntu 7.5.0-3ubuntu1~18.04) 7.5.0, 64-bit
15633 2020-08-01 15:34:25 JST LOG: listening on IPv4 address "0.0.0.0", port 11003
15633 2020-08-01 15:34:25 JST LOG: listening on IPv6 address "::", port 11003
15633 2020-08-01 15:34:25 JST LOG: listening on Unix socket "/tmp/.s.PGSQL.11003"
15633 2020-08-01 15:34:25 JST LOG: redirecting log output to logging collector process
15633 2020-08-01 15:34:25 JST HINT: Future log output will appear in directory "log".
done
server started
pg_terminate_backend
----------------------
t
(1 row)
FATAL: terminating connection due to administrator command
ERROR: unable to forward message to frontend
DETAIL: FATAL error occured on backend
server closed the connection unexpectedly
This probably means the server terminated abnormally
before or while processing the request.
connection to server was lost
2020-08-01 15:34:28: psql pid 15671: LOG: found the pg_terminate_backend request for backend pid:15693 on backend node:0
count_up: 2
count_down: 2
2020-08-01 15:34:33: main pid 15719: DEBUG: initializing pool configuration
2020-08-01 15:34:33: main pid 15719: DETAIL: num_backends: 2 total_weight: 2.000000
2020-08-01 15:34:33: main pid 15719: DEBUG: initializing pool configuration
2020-08-01 15:34:33: main pid 15719: DETAIL: backend 0 weight: 1073741823.500000 flag: 0000
2020-08-01 15:34:33: main pid 15719: DEBUG: initializing pool configuration
2020-08-01 15:34:33: main pid 15719: DETAIL: backend 1 weight: 1073741823.500000 flag: 0000
2020-08-01 15:34:33: main pid 15719: LOG: stop request sent to pgpool. waiting for termination...
.done.
2020-08-01 15:34:34: main pid 15719: DEBUG: shmem_exit(-1): 2 callbacks to make
2020-08-01 15:34:34: main pid 15719: DEBUG: proc_exit(-1): 0 callbacks to make
waiting for server to shut down.... done
server stopped
waiting for server to shut down.... done
server stopped
creating test environment...PostgreSQL major version: 123
Starting set up in native replication mode
creating startall and shutdownall
creating failover script
creating database cluster /home/t-ishii/work/Pgpool-II/current/pgpool2/src/test/regression/tests/073.pg_terminate_backend/testdir/data0...done.
update postgresql.conf
creating pgpool_remote_start
creating basebackup.sh
creating database cluster /home/t-ishii/work/Pgpool-II/current/pgpool2/src/test/regression/tests/073.pg_terminate_backend/testdir/data1...done.
update postgresql.conf
creating pgpool_remote_start
creating basebackup.sh
start all
waiting for pgpool-II coming up...done.
create extensions
node_id | hostname | port | status | lb_weight | role | select_cnt | load_balance_node | replication_delay | replication_state | replication_sync_state | last_status_change
---------+----------+-------+--------+-----------+--------+------------+-------------------+-------------------+-------------------+------------------------+---------------------
0 | /tmp | 11002 | up | 0.500000 | master | 0 | true | 0 | | | 2020-08-01 15:34:37
1 | /tmp | 11003 | up | 0.500000 | slave | 0 | false | 0 | | | 2020-08-01 15:34:37
(2 rows)
shutdown all
pgpool-II setting for native replication mode is done.
To start the whole system, use /home/t-ishii/work/Pgpool-II/current/pgpool2/src/test/regression/tests/073.pg_terminate_backend/testdir/startall.
To shutdown the whole system, use /home/t-ishii/work/Pgpool-II/current/pgpool2/src/test/regression/tests/073.pg_terminate_backend/testdir/shutdownall.
pcp command user name is "t-ishii", password is "t-ishii".
Each PostgreSQL, pgpool-II and pcp port is as follows:
#1 port is 11002
#2 port is 11003
pgpool port is 11000
pcp port is 11001
The info above is in README.port.
done.
waiting for server to start....15952 2020-08-01 15:34:45 JST LOG: starting PostgreSQL 12.3 on x86_64-pc-linux-gnu, compiled by gcc (Ubuntu 7.5.0-3ubuntu1~18.04) 7.5.0, 64-bit
15952 2020-08-01 15:34:45 JST LOG: listening on IPv4 address "0.0.0.0", port 11002
15952 2020-08-01 15:34:45 JST LOG: listening on IPv6 address "::", port 11002
15952 2020-08-01 15:34:45 JST LOG: listening on Unix socket "/tmp/.s.PGSQL.11002"
15952 2020-08-01 15:34:45 JST LOG: redirecting log output to logging collector process
15952 2020-08-01 15:34:45 JST HINT: Future log output will appear in directory "log".
done
server started
waiting for server to start....15967 2020-08-01 15:34:45 JST LOG: starting PostgreSQL 12.3 on x86_64-pc-linux-gnu, compiled by gcc (Ubuntu 7.5.0-3ubuntu1~18.04) 7.5.0, 64-bit
15967 2020-08-01 15:34:45 JST LOG: listening on IPv4 address "0.0.0.0", port 11003
15967 2020-08-01 15:34:45 JST LOG: listening on IPv6 address "::", port 11003
15967 2020-08-01 15:34:45 JST LOG: listening on Unix socket "/tmp/.s.PGSQL.11003"
15967 2020-08-01 15:34:45 JST LOG: redirecting log output to logging collector process
15967 2020-08-01 15:34:45 JST HINT: Future log output will appear in directory "log".
done
server started
pg_terminate_backend
----------------------
t
(1 row)
2020-08-01 15:34:48: psql pid 16011: LOG: found the pg_terminate_backend request for backend pid:16028 on backend node:0
count_up: 2
count_down: 1
connection count is not matched.
2020-08-01 15:34:53: main pid 16057: DEBUG: initializing pool configuration
2020-08-01 15:34:53: main pid 16057: DETAIL: num_backends: 2 total_weight: 2.000000
2020-08-01 15:34:53: main pid 16057: DEBUG: initializing pool configuration
2020-08-01 15:34:53: main pid 16057: DETAIL: backend 0 weight: 1073741823.500000 flag: 0000
2020-08-01 15:34:53: main pid 16057: DEBUG: initializing pool configuration
2020-08-01 15:34:53: main pid 16057: DETAIL: backend 1 weight: 1073741823.500000 flag: 0000
2020-08-01 15:34:53: main pid 16057: LOG: stop request sent to pgpool. waiting for termination...
.WARNING: write on backend 0 failed with error :"Success"
DETAIL: while trying to write data from offset: 0 wlen: 5
server closed the connection unexpectedly
This probably means the server terminated abnormally
before or while processing the request.
connection to server was lost
done.
2020-08-01 15:34:54: main pid 16057: DEBUG: shmem_exit(-1): 2 callbacks to make
2020-08-01 15:34:54: main pid 16057: DEBUG: proc_exit(-1): 0 callbacks to make
waiting for server to shut down....... done
server stopped
waiting for server to shut down....... done
server stopped
More information about the pgpool-hackers
mailing list