pgpool

WARNING: Segmentation Faults in these executables

logwatchの出力に以下の記録がありました。
 --------------------- Kernel Begin ------------------------

 WARNING:  Segmentation Faults in these executables
    pgpool :  1 Time(s)

 1 Time(s): Code: 8b 44 24 38 4c 8b 3c 24 8d 50 ff 49 8b 84 24 80 00 00 00 4c 89 ff 48 8d 70 01 e8 5f f6 ff ff 48 89 c7 48 89 04 24 49 8b 47 70 <48> 8b 00 48 85 c0 0f 84 c5 01 00 00 49 8b 57 78 31 f6 ff d0 48 89

 ---------------------- Kernel End -------------------------
そこでmessagesを確認しました。

/var/log/messagesの出力
 # cat messages-20230602 | grep 21:35
Jun  1 21:35:32 sakura kernel: Code: 8b 44 24 38 4c 8b 3c 24 8d 50 ff 49 8b 84 24 80 00 00 00 4c 89 ff 48 8d 70 01 e8 5f f6 ff ff 48 89 c7 48 89 04 24 49 8b 47 70 <48> 8b 00 48 85 c0 0f 84 c5 01 00 00 49 8b 57 78 31 f6 ff d0 48 89
Jun  1 21:35:32 sakura systemd[1]: Started Process Core Dump (PID 3000525/UID 0).
Jun  1 21:35:33 sakura systemd-coredump[3000526]: Resource limits disable core dumping for process 2998804 (pgpool).
Jun  1 21:35:33 sakura systemd-coredump[3000526]: Process 2998804 (pgpool) of user 26 dumped core.
Jun  1 21:35:33 sakura systemd[1]: systemd-coredump@7-3000525-0.service: Succeeded.
コアダンプを確認します。
# coredumpctl info -1
           PID: 2998804 (pgpool)
           UID: 26 (postgres)
           GID: 26 (postgres)
        Signal: 11 (SEGV)
     Timestamp: Thu 2023-06-01 21:35:32 JST (10h ago)
  Command Line: pgpool: ap3 ap2 127.0.0.1(46500) SELECT
    Executable: /usr/bin/pgpool
 Control Group: /system.slice/pgpool.service
          Unit:
         Slice: system.slice
       Boot ID: 271c5cf67c8a43e98f20ff425b76fbb4
    Machine ID: 695a939c5d6449a087f6d36503d37bec
      Hostname: sakura
       Storage: none
       Message: Process 2998804 (pgpool) of user 26 dumped core.
「-1」のオプションは直近のコアダンプを確認するというものです。
マニュアルの記述は以下の通りです。
Show information of a single core dump only, instead of listing all known core dumps.
そういえば最近ちょくちょく同じメッセージがでていたので、すべてのコアダンプを確認します。
# coredumpctl info
           PID: 608872 (pgpool)
           UID: 26 (postgres)
           GID: 26 (postgres)
        Signal: 11 (SEGV)
     Timestamp: Wed 2023-05-24 07:37:23 JST (1 weeks 2 days ago)
  Command Line: pgpool: ap3 ap2 127.0.0.1(59504) SELECT
    Executable: /usr/bin/pgpool
 Control Group: /system.slice/pgpool.service
          Unit:
         Slice: system.slice
       Boot ID: 271c5cf67c8a43e98f20ff425b76fbb4
    Machine ID: 695a939c5d6449a087f6d36503d37bec
      Hostname: sakura
       Storage: none
       Message: Process 608872 (pgpool) of user 26 dumped core.

           PID: 1636000 (pgpool)
           UID: 26 (postgres)
           GID: 26 (postgres)
        Signal: 11 (SEGV)
     Timestamp: Sun 2023-05-28 01:30:35 JST (5 days ago)
  Command Line: pgpool: ap3 ap2 127.0.0.1(37008) SELECT
    Executable: /usr/bin/pgpool
 Control Group: /system.slice/pgpool.service
          Unit:
         Slice: system.slice
       Boot ID: 271c5cf67c8a43e98f20ff425b76fbb4
    Machine ID: 695a939c5d6449a087f6d36503d37bec
      Hostname: sakura
       Storage: none
       Message: Process 1636000 (pgpool) of user 26 dumped core.

           PID: 1827919 (pgpool)
           UID: 26 (postgres)
           GID: 26 (postgres)
        Signal: 11 (SEGV)
     Timestamp: Sun 2023-05-28 18:42:12 JST (4 days ago)
  Command Line: pgpool: ap3 ap2 127.0.0.1(51772) SELECT
    Executable: /usr/bin/pgpool
 Control Group: /system.slice/pgpool.service
          Unit:
         Slice: system.slice
       Boot ID: 271c5cf67c8a43e98f20ff425b76fbb4
    Machine ID: 695a939c5d6449a087f6d36503d37bec
      Hostname: sakura
       Storage: none
       Message: Process 1827919 (pgpool) of user 26 dumped core.

           PID: 1950651 (pgpool)
           UID: 26 (postgres)
           GID: 26 (postgres)
        Signal: 11 (SEGV)
     Timestamp: Mon 2023-05-29 03:30:50 JST (4 days ago)
  Command Line: pgpool: ap3 ap2 127.0.0.1(43044) SELECT
    Executable: /usr/bin/pgpool
 Control Group: /system.slice/pgpool.service
          Unit:
         Slice: system.slice
       Boot ID: 271c5cf67c8a43e98f20ff425b76fbb4
    Machine ID: 695a939c5d6449a087f6d36503d37bec
      Hostname: sakura
       Storage: none
       Message: Process 1950651 (pgpool) of user 26 dumped core.

           PID: 2998804 (pgpool)
           UID: 26 (postgres)
           GID: 26 (postgres)
        Signal: 11 (SEGV)
     Timestamp: Thu 2023-06-01 21:35:32 JST (10h ago)
  Command Line: pgpool: ap3 ap2 127.0.0.1(46500) SELECT
    Executable: /usr/bin/pgpool
 Control Group: /system.slice/pgpool.service
          Unit:
         Slice: system.slice
       Boot ID: 271c5cf67c8a43e98f20ff425b76fbb4
    Machine ID: 695a939c5d6449a087f6d36503d37bec
      Hostname: sakura
       Storage: none
       Message: Process 2998804 (pgpool) of user 26 dumped core.

前に同じ事象が発生したときは、php-fpmのrestartで回復したので、とりあえずphp-fpmをrestartしました。
# systemctl restart php-fpm.service
コアダンプはgdbで見られるそうなので、見ようとしたところコアダンプがありませんでした…

# coredumpctl gdb -1
           PID: 2998804 (pgpool)
           UID: 26 (postgres)
           GID: 26 (postgres)
        Signal: 11 (SEGV)
     Timestamp: Thu 2023-06-01 21:35:32 JST (10h ago)
  Command Line: pgpool: ap3 ap2 127.0.0.1(46500) SELECT
    Executable: /usr/bin/pgpool
 Control Group: /system.slice/pgpool.service
          Unit:
         Slice: system.slice
       Boot ID: 271c5cf67c8a43e98f20ff425b76fbb4
    Machine ID: 695a939c5d6449a087f6d36503d37bec
      Hostname: sakura
       Storage: none
       Message: Process 2998804 (pgpool) of user 26 dumped core.

Coredump entry has no core attached (neither internally in the journal nor externally on disk).
ulimitコマンドで確認すると、core file sizeが0でしたので…、unlimitedに変更しました。
# ulimit -a
core file size          (blocks, -c) 0
# ulimit -c unlimited
# ulimit -a
core file size          (blocks, -c) unlimited
また再起動後も設定を有効にするため、以下のように設定しました。
# emacs /etc/security/limits.d/90-core.conf
90-core.confに以下の内容を追加
* soft core unlimited
* hard core unlimited
すべてのユーザー(*)に対してソフトおよびハードの core file size を無制限に設定します。
特定のユーザーだけに適用したい場合、* の代わりにユーザー名を使用します。

次にコアダンプをグローバルに有効にします。
# emacs /etc/sysctl.conf
/etc/sysctl.confに以下の内容を追加
kernel.core_pattern = /coredumpsへのパス/core.%e.%p
fs.suid_dumpable = 2
この設定は、コアダンプファイルのファイル名を設定し、SUIDプログラムでもコアダンプが生成されるようにしています。
設定を反映します。
# sudo sysctl -p
コアダンプを保存するディレクトリが、すべてのユーザーに対して書き込み可能にします。
sudo mkdir -p /coredumpsへのパス
sudo chmod 1777 /coredumpsへのパス
コアダンプが生成されているかどうかをテストするために、クラッシュする簡単なプログラムを作成して実行します。
crash.c
#include <stdlib.h>

int main() {
    abort();
}
コンパイルして実行し、指定したディレクトリにコアダンプファイルが生成されることを確認します。
$ gcc -o crash crash.c
$ ./crash
$ ls -l /var/tmp/core/
total 160
-rw------- 1 ap2 ap2 253952 Jun 15 08:09 core.crash.2340294
2023/06/19 追記
まだコアダンプが生成されませんでした。
#  coredumpctl gdb -1
           PID: 1964404 (pgpool)
           UID: 26 (postgres)
           GID: 26 (postgres)
        Signal: 11 (SEGV)
     Timestamp: Wed 2023-06-14 00:43:50 JST (5 days ago)
  Command Line: pgpool: ap3 ap2 127.0.0.1(36308) SELECT
    Executable: /usr/bin/pgpool
 Control Group: /system.slice/pgpool.service
          Unit:
         Slice: system.slice
       Boot ID: 35ca3e38a1bd486194253de42de9c7c7
    Machine ID: 695a939c5d6449a087f6d36503d37bec
      Hostname: sakura
       Storage: none
       Message: Process 1964404 (pgpool) of user 26 dumped core.

Coredump entry has no core attached (neither internally in the journal nor externally on disk).
pgpoolのプロセスのmax core file sizeを確認したところ、SOFTが0になっていました。
# ps ax | grep pgpool | more
3257315 ?        Ss     0:17 /usr/bin/pgpool -f /etc/pgpool-II/pgpool.conf -n
(以下略)

# prlimit 3257315
RESOURCE   DESCRIPTION                             SOFT      HARD UNITS
AS         address space limit                unlimited unlimited bytes
CORE       max core file size                 unlimited unlimited bytes
(以下略)
pgpoolのソフトリミットをunlimitedに変更します。
# prlimit --pid 3257315 --core=unlimited:unlimited
また、pgpoolのサービスユニットファイルを変更して、LimitCOREをinfinityにしておきます。
まずサービスユニットファイルの場所を確認します。
# systemctl status pgpool.service
● pgpool.service - Pgpool-II
   Loaded: loaded (/usr/lib/systemd/system/pgpool.service; enabled; vendor preset: disabled)
以下の通り設定を追加します。
[Unit]
Description=Pgpool-II
After=syslog.target network.target

[Service]

User=postgres
Group=postgres

EnvironmentFile=-/etc/sysconfig/pgpool

LimitCORE=infinity
ExecStart=/usr/bin/pgpool -f /etc/pgpool-II/pgpool.conf $OPTS
ExecStop=/usr/bin/pgpool -f /etc/pgpool-II/pgpool.conf $STOP_OPTS stop
ExecReload=/usr/bin/pgpool -f /etc/pgpool-II/pgpool.conf reload

[Install]
WantedBy=multi-user.target

2023/07/01追記
事象が再現しましたので、コアダンプを確認しようとしたところ、以下のように出力されました。
# coredumpctl info -1
No match found.
なにか設定にしくじっていると思います…
coredumpctlはsystemdで動く…という表現でいいのかな…のですが、先日の設定のどこかでsystemdと競合する何かを設定してしまっている気がします。
コアダンプファイルを出力するように設定した/var/tmp/core/ディレクトリに、コアダンプファイルが生成されていましたので、とりあえず解析をすることにしました。
# ls -l /var/tmp/core/
-rw------- 1 postgres postgres 154488832 Jun 30 16:59 core.pgpool.3071815
解析方法は初心者のためのコアファイルの解析方法についてを読んで実施しました。
# gdb /usr/bin/pgpool /var/tmp/core/core.pgpool.3071815
GNU gdb (GDB) Red Hat Enterprise Linux 8.2-19.el8
Copyright (C) 2018 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later 
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.
Type "show copying" and "show warranty" for details.
This GDB was configured as "x86_64-redhat-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
.
Find the GDB manual and other documentation resources online at:
    .

For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from /usr/bin/pgpool...Reading symbols from /usr/lib/debug/usr/bin/pgpool-4.1.16-1pgdg.rhel8.x86_64.debug...done.
done.

warning: Can't open file (null) during file-backed mapping note processing

warning: Can't open file (null) during file-backed mapping note processing

warning: Can't open file (null) during file-backed mapping note processing

warning: Can't open file (null) during file-backed mapping note processing

warning: Can't open file (null) during file-backed mapping note processing

warning: Can't open file (null) during file-backed mapping note processing

warning: Can't open file (null) during file-backed mapping note processing

warning: Can't open file (null) during file-backed mapping note processing

warning: Can't open file (null) during file-backed mapping note processing

warning: Can't open file (null) during file-backed mapping note processing

warning: Can't open file (null) during file-backed mapping note processing

warning: Can't open file (null) during file-backed mapping note processing

warning: Can't open file (null) during file-backed mapping note processing
[New LWP 3071815]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `pgpool: ap3 ap2 127.0.0.1(34752) SELECT         '.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  0x00005589153a0ffc in psql_yylex (yylval_param=yylval_param@entry=0x0, yyscanner=<optimized out>)
    at utils/psqlscan.l:712
712                                                     value = cur_state->callbacks->get_variable(varname,
(gdb) backtrace
#0  0x00005589153a0ffc in psql_yylex (yylval_param=yylval_param@entry=0x0, yyscanner=<optimized out>)
    at utils/psqlscan.l:712
#1  0x00005589153a1a67 in psql_scan (state=state@entry=0x5589164a15d8, query_buf=query_buf@entry=0x7ffd2f6f0250,
    prompt=prompt@entry=0x7ffd2f6f024c) at utils/psqlscan.l:1149
#2  0x0000558915368f0e in multi_statement_query (
    queries=0x558916486de8 "SELECT \r\n\t'\r\n<!-- jQuery library  -->\r\n<script type=\"text/javascript\" src=\"https://code.jquery.com/jquery-1.11.1.min.js\"></script>\r\n<!-- WEB Fonts  -->\r\n<link href=\\'http://fonts.googleapis.com/css?fa"...) at protocol/pool_proto_modules.c:4131
#3  SimpleQuery (frontend=frontend@entry=0x5589164474f8, backend=backend@entry=0x7fb6f19bb9d0, len=107421,
    contents=contents@entry=0x558916486de8 "SELECT \r\n\t'\r\n<!-- jQuery library  -->\r\n<script type=\"text/javascript\" src=\"https://code.jquery.com/jquery-1.11.1.min.js\"></script>\r\n<!-- WEB Fonts  -->\r\n<link href=\\'http://fonts.googleapis.com/css?fa"...) at protocol/pool_proto_modules.c:266
#4  0x000055891536ef30 in ProcessFrontendResponse (frontend=frontend@entry=0x5589164474f8,
    backend=backend@entry=0x7fb6f19bb9d0) at protocol/pool_proto_modules.c:2597
#5  0x0000558915360d6e in read_packets_and_process (frontend=<optimized out>, backend=<optimized out>,
    reset_request=<optimized out>, state=<optimized out>, num_fields=<optimized out>, cont=<optimized out>)
    at protocol/pool_process_query.c:4986
#6  0x00005589153615e3 in pool_process_query (frontend=<optimized out>, backend=<optimized out>,
    reset_request=<optimized out>) at protocol/pool_process_query.c:291
#7  0x000055891535b0f8 in do_child (fds=fds@entry=0x558916445de0) at protocol/child.c:431
#8  0x0000558915332467 in fork_a_child (fds=0x558916445de0, id=57) at main/pgpool_main.c:703
#9  0x0000558915332cd9 in reaper () at main/pgpool_main.c:2855
#10 0x000055891533aa64 in PgpoolMain (discard_status=<optimized out>, clear_memcache_oidmaps=<optimized out>)
    at main/pgpool_main.c:491
#11 0x0000558915330715 in main (argc=<optimized out>, argv=0x7ffd2f700318) at main/main.c:356
(gdb) list
707
708                                             varname = psqlscan_extract_substring(cur_state,
709                                                                                                                      yytext + 1,
710                                                                                                                      yyleng - 1);
711                                             if (cur_state->callbacks->get_variable)
712                                                     value = cur_state->callbacks->get_variable(varname,
713                                                                                                                           PQUOTE_PLAIN,
714                                                                                                                           cur_state->cb_passthrough);
715                                             else
716                                                     value = NULL;
(gdb) info locals
varname = 0x5589164a1668 "first"
value = 
cur_state = 
output_buf = 
yyless_macro_arg = 
yyless_macro_arg = 
yyless_macro_arg = 
yyless_macro_arg = 
yyless_macro_arg = 
yyless_macro_arg = 
yy_current_state = 
yy_cp = 
yy_bp = 0x5589164a7780 ":first"
yy_act = 
yyg = 
backtraceで表示されているSQLを検索して実行したところ、Segmentation faultしました。 このSQLはユーザーさんが作成されたもので、現在のPostgreSQLではそもそも動かないSQLであることを確認したので無効化しました。 なぜSegmentation faultするかの原因を探りたかったのですが、元のSQLが複雑すぎることと、現在のシングルクォーテーションのエスケープ方法ではないエスケープ方法を使っていたので諦めました。

pgpool-II-pg11の4.1.9から4.1.10へのdnf updateによるVerUPについて

pgpool-II-pg11の4.1.9から4.1.10へのdnf updateによるVerUPをしようとしたところpgpool-II-pg11-extensions.x86_64だけpgdg11を参照してしまいます。

[質問]
pgdg11のpgpool-II-pg11-extensionsを参照してしまう理由をご教示頂きたいです。

[環境]
# cat /etc/redhat-release
AlmaLinux release 8.5 (Arctic Sphynx)

# ls /etc/yum.repos.d/
(中略)
pgpool-II-release-41.repo
pgdg-redhat-all.repo
(以下略)

# cat /etc/yum.repos.d/pgpool-II-release-41.repo
[pgpool41]
name=pgpool-II 4.1 $releasever - $basearch
baseurl=https://www.pgpool.net/yum/rpms/4.1/redhat/rhel-$releasever-$basearch
enabled=1
gpgcheck=1
gpgkey=file:///etc/pki/rpm-gpg/RPM-GPG-KEY-PGPOOL2
(以下略)

# cat /etc/yum.repos.d/pgdg-redhat-all.repo
(中略)
[pgdg11]
name=PostgreSQL 11 for RHEL/CentOS $releasever - $basearch
baseurl=https://download.postgresql.org/pub/repos/yum/11/redhat/rhel-$releasever-$basearch
enabled=1
gpgcheck=1
gpgkey=file:///etc/pki/rpm-gpg/RPM-GPG-KEY-PGDG
(以下略)
[dnf updateの出力]
(中略)
エラー:
  問題: パッケージの最良アップデート候補をインストールできません pgpool-II-pg11-extensions-4.1.9-1pgdg.rhel8.x86_64
   - pgpool-II が提供されません pgpool-II-pg11-extensions-4.3.0-1.rhel8.x86_64 に必要です
   - libpcp.so.2()(64bit) が提供されません pgpool-II-pg11-extensions-4.3.0-1.rhel8.x86_64 に必要です
   - pgpool-II-pcp が提供されません pgpool-II-pg11-extensions-4.3.0-1.rhel8.x86_64 に必要です
(インストール不可のパッケージをスキップするには、'--skip-broken' を追加してみてください または、'--nobest' を追加して、最適    候補のパッケージのみを使用しないでください)
(中略)
pgpool-II-pg11.x86_64                                              4.1.10-1pgdg.rhel8                           pgpool41
pgpool-II-pg11-debuginfo.x86_64                                    4.1.10-1pgdg.rhel8                           pgpool41
pgpool-II-pg11-debugsource.x86_64                                  4.1.10-1pgdg.rhel8                           pgpool41
pgpool-II-pg11-devel.x86_64                                        4.1.10-1pgdg.rhel8                           pgpool41
pgpool-II-pg11-extensions.x86_64                                   4.3.0-1.rhel8                                pgdg11
pgpool-II-pg11-extensions-debuginfo.x86_64                         4.1.10-1pgdg.rhel8                           pgpool41
(中略)
※pgpool-II-pg11-extensionsだけpgdg11を参照してしまう
彭さんの回答

PostgreSQLのリポジトリに含まれるPgpool-IIのRPMパッケージの名前がpgpool-II-pg11-extensions.x86_64 に変更されたので、例えば、「dnf install pgpool-II-pg11-*」でインストールすると、pgpool-II-pg11-extensions が PostgreSQL のリポジトリからインストールされてしまいます。

Pgpool-II のパッケージを pgdg からインストールしないように、/etc/yum.repos.d/pgdg-redhat-all.repo に exclude 設定を追加する必要があります。

# vi /etc/yum.repos.d/pgdg-redhat-all.repo
(以下のexcludeの設定を追加)
[pgdg-common]
...
exclude=pgpool*


[pgdg14]
...
exclude=pgpool*

[pgdg13]
...
exclude=pgpool*

[pgdg12]
...
exclude=pgpool*

[pgdg11]
...
exclude=pgpool*

[pgdg10]
...
exclude=pgpool*

[pgdg96]
...
exclude=pgpool*

pgpoolのlog_destination

この話題は、pgpoolとCentOS8の話です。

pgpoolの設定の一つである「log_destination」はログの出力先を指定します。
設定値は、「stdder」、「syslog」、「stdder,syslog」の3種類です。

log_destinationを「stdder,syslog」に設定し、rsyslog.confをそれなりに設定し、これで/var/log/pgpool/pgpool.logにだけログが出力されると思ったら、/var/log/pgpool/pgpool.logにも、/var/log/messagesにも出力されていました。
log_destinationを「syslog」に設定して、思ったとおりの動作になりました。

「stdder,syslog」と設定すると、pgpoolはstdderにもsyslogにもログを出力します。
stdderに出力されたログは、systemdがjournaldに渡します。
journaldは渡されたログをrsyslogdに渡します。
# cat /etc/rsyslog.conf
<中略>
module(load="imjournal"             # provides access to the systemd journal
       StateFile="imjournal.state") # File to store the position in the journal

log_destinationを「stdder,syslog」に設定すると、「syslog」の設定がrsyslogd経由でログを書き込み、「stdder」の設定が、journald→rsyslogd経由でログを書き込む、動作になります。

log_destinationを「syslog」にしてログを保存する場合の設定は公式マニュアル、「stdder」にしてログを保存する場合はpgpool logging on centos 7 | Pierre Timmermansを参照するといいと思います。

Apache + pgpool + PostgreSQLで、Apacheがtimeoutで504を返すとき、PostgreSQLのクエリが残ったままになる

この文書はApache2.4.37とPostgreSQL11.7とpgpool4.1.1の話題です。

Apache + pgpool + PostgreSQLで、Apacheがtimeoutで504を返すとき、PostgreSQLのクエリが残ったままになることがあります。

ErogameScapeのApacheはtimeoutを120秒に設定しています。
時間のかかるクエリを実行して120秒を超えてしまうとApacheは504を返します。
このとき実行されたクエリがpsコマンドで見ると実行されっぱなしになっているように見えます。
[ap2@sakura ~]$ ps ax | grep 28908
 8134 pts/0    S+     0:00 grep --color=auto 28908
28908 ?        Ss     0:00 postgres: ap2 ap2 127.0.0.1(55878) UPDATE
このPostgreSQLのプロセスに対応するpgpoolのプロセスを確認するとidleまたはidle in transactionになります。
[ap2@sakura ~]$ ps ax | grep 27546
 8121 pts/0    S+     0:00 grep --color=auto 27546
27546 ?        S      0:00 pgpool: ap2 ap2 127.0.0.1(58634) idle in transaction
このまましておくと、PostgreSQLのクエリがテーブルをロックしたままになってしまっているので、pgpool + PostgreSQLの構成においてテーブルをロックしているPostgreSQLのSQLをキャンセルしたいの記事の方法でpgpoolのプロセスを殺します。

なぜこのような状態になってしまうのか分かりません…
解決方法は、Apacheのtimeoutの設定をのばす、クエリを見直してtimeout以内に収まるようにする、なのですが、根本的な解決方法ではないので困っております。

pgpool + PostgreSQLの構成においてテーブルをロックしているPostgreSQLのSQLをキャンセルしたい

この文書はPostgreSQL11.7とpgpool4.1.1の話題です。

なんらかの理由でテーブルをロックしたままのPostgreSQLのSQLをキャンセルしてロックを開放したい場合以下の関数を使います。


この関数は成功するとtrueを返すのですが、trueが返ってきたからといって、キャンセルできる(プロセスを終了できる)わけではありません。
以下に例を示します。
ap2=# select l.pid , a.backend_start from (select pid from pg_locks group by pid) l,pg_stat_activity a where l.pid=a.pid order by query_start;
  pid  |         backend_start
-------+-------------------------------
 10673 | 2020-05-06 14:06:57.721961+09
 18222 | 2020-05-06 15:52:12.091632+09
 28546 | 2020-05-06 16:30:04.77062+09
(3 rows)

ap2=# SELECT pg_cancel_backend(10673);
 pg_cancel_backend
-------------------
 t
(1 row)

ap2=# SELECT pg_cancel_backend(18222);
 pg_cancel_backend
-------------------
 t
(1 row)

ap2=# select l.pid , a.backend_start from (select pid from pg_locks group by pid) l,pg_stat_activity a where l.pid=a.pid order by query_start;
  pid  |         backend_start
-------+-------------------------------
 10673 | 2020-05-06 14:06:57.721961+09
 18222 | 2020-05-06 15:52:12.091632+09
 28546 | 2020-05-06 16:30:04.77062+09
(3 rows)
10673と18222のプロセスを終了したいのですが、終了できません。
pg_terminate_backend(pid int)を使うと終了できるのですが、pgpoolを使っている場合、pg_terminate_backendを使うとpgpoolがPostgreSQLを切り離すので、サービスが中断します。

ErogameScapeにおいて、上記のようにpg_cancel_backendがきかないのは以下のような状況のときのようでした。

Apacheにアクセス
php-fpmがpgpoolにクエリを発行
pgpoolがPostgreSQLにクエリを発行
クエリの実行に時間がかかる
一定時間たってもphp-fpmから応答がないのでApacheがtimeoutとしてユーザーに504を返す
このあとpsコマンドで確認すると
pgpoolはidleもしくはidle in transaction
PostgreSQLはSELECTだったりUPDATEだったりpgpoolが発行したSQLを実行している状態

以下、例を示します。
[root@sakura ap2]# cat /var/log/httpd/access_log | grep update
127.0.0.1 - - [08/May/2020:04:40:01 +0900] "GET /~ap2/ero/toukei_kaiseki/update_userreview_display_log.php HTTP/1.1" 504 247 "-" "Wget/1.19.5 (linux-gnu)" 60027802
127.0.0.1 - - [08/May/2020:04:41:02 +0900] "GET /~ap2/ero/toukei_kaiseki/update_userreview_display_log.php HTTP/1.1" 504 247 "-" "Wget/1.19.5 (linux-gnu)" 60060326
127.0.0.1 - - [08/May/2020:04:42:04 +0900] "GET /~ap2/ero/toukei_kaiseki/update_userreview_display_log.php HTTP/1.1" 200 462 "-" "Wget/1.19.5 (linux-gnu)" 6428
[root@sakura ap2]# cat /var/lib/pgsql/11/log/postgresql-Fri.log
2020-05-08 04:41:10.718 JST [28908] [ap2] LOG:  duration: 8271.792 ms  execute : UPDATE userreview SET display_unique_count = coalesce( display_unique_count , 0 ) + $1 WHERE uid = $2 AND game = $3 ;
ap2=# select * from (select pid from pg_locks group by pid) l,pg_stat_activity a where l.pid=a.pid order by query_start;
  pid  |  datid   | datname |  pid  | usesysid | usename | application_name | client_addr | client_hostname | client_port |
        backend_start         |          xact_start           |          query_start          |         state_change
  | wait_event_type | wait_event | state  | backend_xid | backend_xmin |
     query                                                         |  backend_type
-------+----------+---------+-------+----------+---------+------------------+-------------+-----------------+-------------+-
------------------------------+-------------------------------+-------------------------------+-----------------------------
--+-----------------+------------+--------+-------------+--------------+----------------------------------------------------
-------------------------------------------------------------------+----------------
 28908 | 10934808 | ap2     | 28908 |    16385 | ap2     |                  | 127.0.0.1   |                 |       55878 |
2020-05-08 04:41:01.103872+09 | 2020-05-08 04:41:02.407331+09 | 2020-05-08 04:41:02.446477+09 | 2020-05-08 04:41:02.446478+0
9 | Client          | ClientRead | active |    17877103 |              | UPDATE userreview SET display_unique_count = coales
ce( display_unique_count , 0 ) + $1 WHERE uid = $2 AND game = $3 ; | client backend
この状態で
SELECT pg_cancel_backend(28908);
しても、28908を終了させることができません。

28908を使っているpgpoolのプロセスを殺したところ、28908を終了させることができました。
pcp_proc_infoコマンドで28908を使っているpgpoolのプロセスIDを確認します。
[ap2@sakura ~]$ pcp_proc_info -h /var/run/postgresql/ -U pgpool | grep 28908
Password:
ap2 ap2 2020-05-08 04:36:00 2020-05-08 04:41:01 3 0 2 28908 1 27546 0
28908と27546のプロセスを確認します。
[ap2@sakura ~]$ ps ax | grep 27546
 8121 pts/0    S+     0:00 grep --color=auto 27546
27546 ?        S      0:00 pgpool: ap2 ap2 127.0.0.1(58634) idle in transaction
[ap2@sakura ~]$ ps ax | grep 28908
 8134 pts/0    S+     0:00 grep --color=auto 28908
28908 ?        Ss     0:00 postgres: ap2 ap2 127.0.0.1(55878) UPDATE
27546をkillします。
※確か、kill 27546では殺せなくて、kill -KILL 27546で殺しました。
これで、28908のプロセスも開放されて、ロックされていたテーブルもロックが解除されました。

※そもそも、なぜpostgresがSELECTやUPDATEのまま止まってしまうのかの原因は未だ分かりません…

failover_on_backend_error


failover_on_backend_errorをoffにすると、pgpoolがフェイルオーバーの処理をしてくれなくなるので、別の仕組みでフェイルオーバーの仕組みを実装する必要があります。

health_check_max_retreisを有効にするのは、ネットワークが不安定になることがあるので、health_checkのリトライをしたい場合であって、pgpoolのフェイルオーバーは依然として必要だと思いますので、onのままにすることが多いのでは無いかと思います。
※「health_check_max_retreisを有効にする場合は、failover_on_backend_errorを無効にするのが望ましい」理由が分かりませんでした…

あまり考えずにfailover_on_backend_errorをoffに設定したら、以下の事象が発生しサービスが中断しました。
以下pgpoolのログです。
May 31 23:10:44 erogamescape13 pgpool[12780]: [313206-1] 2019-05-31 23:10:44: pid 12780: LOG:  trying connecting to PostgreSQL server on "192.168.0.14:5432" by INET socket
May 31 23:10:44 erogamescape13 pgpool[12780]: [313206-2] 2019-05-31 23:10:44: pid 12780: DETAIL:  timed out. retrying...
May 31 23:10:54 erogamescape13 pgpool[12780]: [313207-1] 2019-05-31 23:10:54: pid 12780: LOG:  trying connecting to PostgreSQL server on "192.168.0.14:5432" by INET socket
May 31 23:10:54 erogamescape13 pgpool[12780]: [313207-2] 2019-05-31 23:10:54: pid 12780: DETAIL:  timed out. retrying...
May 31 23:11:04 erogamescape13 pgpool[12780]: [313208-1] 2019-05-31 23:11:04: pid 12780: LOG:  trying connecting to PostgreSQL server on "192.168.0.14:5432" by INET socket
May 31 23:11:04 erogamescape13 pgpool[12780]: [313208-2] 2019-05-31 23:11:04: pid 12780: DETAIL:  timed out. retrying...
May 31 23:11:14 erogamescape13 pgpool[12780]: [313209-1] 2019-05-31 23:11:14: pid 12780: LOG:  trying connecting to PostgreSQL server on "192.168.0.14:5432" by INET socket
May 31 23:11:14 erogamescape13 pgpool[12780]: [313209-2] 2019-05-31 23:11:14: pid 12780: DETAIL:  timed out. retrying...
May 31 23:11:24 erogamescape13 pgpool[12780]: [313210-1] 2019-05-31 23:11:24: pid 12780: LOG:  trying connecting to PostgreSQL server on "192.168.0.14:5432" by INET socket
May 31 23:11:24 erogamescape13 pgpool[12780]: [313210-2] 2019-05-31 23:11:24: pid 12780: DETAIL:  timed out. retrying...
May 31 23:11:34 erogamescape13 pgpool[12780]: [313211-1] 2019-05-31 23:11:34: pid 12780: LOG:  trying connecting to PostgreSQL server on "192.168.0.14:5432" by INET socket
May 31 23:11:34 erogamescape13 pgpool[12780]: [313211-2] 2019-05-31 23:11:34: pid 12780: DETAIL:  timed out. retrying...
May 31 23:11:37 erogamescape13 pgpool[12780]: [313212-1] 2019-05-31 23:11:37: pid 12780: LOG:  failed to connect to PostgreSQL server on "192.168.0.14:5432", getsockopt() detected error "Connection timed out"
May 31 23:11:37 erogamescape13 pgpool[12780]: [313213-1] 2019-05-31 23:11:37: pid 12780: LOG:  failed to create a backend 0 connection
May 31 23:11:37 erogamescape13 pgpool[12780]: [313213-2] 2019-05-31 23:11:37: pid 12780: DETAIL:  skip this backend because because failover_on_backend_error is off and we are in streaming replication mode and node is standby node
May 31 23:11:37 erogamescape13 pgpool[12780]: [313214-1] 2019-05-31 23:11:37: pid 12780: LOG:  master node 0 is down. Update master node to 1
May 31 23:11:37 erogamescape13 pgpool[12780]: [313215-1] 2019-05-31 23:11:37: pid 12780: LOG:  failback event detected
May 31 23:11:37 erogamescape13 pgpool[12780]: [313215-2] 2019-05-31 23:11:37: pid 12780: DETAIL:  restarting myself
May 31 23:11:38 erogamescape13 pgpool[13944]: [313288-1] 2019-05-31 23:11:38: pid 13944: ERROR:  unable to read message kind
May 31 23:11:38 erogamescape13 pgpool[13944]: [313288-2] 2019-05-31 23:11:38: pid 13944: DETAIL:  kind does not match between master(0) slot[0] (52)
health_check_max_retreisを3に設定していたのに、どうしてconnectingが6回timeoutしているのか分からないのですが、6回timeoutして、failed to create a backend 0 connectionと判定しています。
※ちなみにbackend0のPostgreSQLはprimaryでした。

ここで、backend 0を切り離して、事前に用意したフェイルオーバーのためのスクリプトをpgpoolが起動して、backend 1を昇格させる必要があるのですが、failover_on_backend_errorがoffなので、pgpoolは何もせず(skip this backend because because failover_on_backend_error is off)、でもpgpoolとしては、backend 1がprimaryだと判断して動き始めます(Update master node to 1)。

しかし、実際はbackend 1はstandbyのままなので、kind does not match between master(0) slot[0]となってPostgreSQLに接続出来ず、サービスが中断しました。

postmaster on DB node 1 was shutdown by administrative command

pgpoolで以下のログを出力してPostgreSQLが切り離されてしまう事象が発生しました。
May 28 04:40:03 erogamescape13 pgpool[12457]: [74016-2] 2019-05-28 04:40:03: pid 12457: DETAIL:  postmaster on DB node 1 was shutdown by administrative command
May 28 04:40:03 erogamescape13 pgpool[12457]: [74017-1] 2019-05-28 04:40:03: pid 12457: LOG:  received degenerate backend request for node_id: 1 from pid [12457]
PostgreSQLの方では以下のログを出力しています。
2019-05-28 04:40:01.414 JST [12646] FATAL:  terminating connection due to administrator command
このメッセージを発生させるような処理はしていない…(pg_terminate_backendでプロセスを終了させると出るそうですが、そのような処理はしていない…)ので、何が起きたのか謎です。

出来ることはPostgreSQLのログのレベルを深くして、同じ事象が出た時に何かログに記録されることを期待します。
具体的には以下のとおりログのレベルを変更しました。
[root@erogamescape13 log]# emacs /var/lib/pgsql/11/data/postgresql.conf

- client_min_messages = notice
+ client_min_messages = log

- log_min_messages = warning
+ log_min_messages = info

- log_min_error_statement = error
+ log_min_error_statement = warning

ここまでたどり着くのにpgpoolのソースをおってしまったので、そのおいかたを記録に残しておきます。※自分、C言語はわからないので、雰囲気だけでおいました。
find . -type f | grep .c$ | xargs grep -n "postmaster on DB node"
で、postmaster on DB node 1 was shutdown by administrative commandのメッセージがどこで出力されるか調べる。
./src/protocol/pool_process_query.c:4858:

				r = detect_postmaster_down_error(CONNECTION(backend, i), MAJOR(backend));
				if (r == SPECIFIED_ERROR)
				{
					ereport(LOG,
							(errmsg("reading and processing packets"),
							 errdetail("postmaster on DB node %d was shutdown by administrative command", 
pool_process_query.cで、detect_postmaster_down_error関数の結果がSPECIFIED_ERRORの場合にpostmaster on DB node %d was shutdown by administrative commandが出る。
detect_postmaster_down_error関数を探して見てみる。
detect_postmaster_down_error(POOL_CONNECTION * backend, int major)
{
	int			r = detect_error(backend, ADMIN_SHUTDOWN_ERROR_CODE, major, 'E', false);

	return r;
}
SPECIFIED_ERRORがなんなのかわからないけど、detect_errorの引数にADMIN_SHUTDOWN_ERROR_CODEが与えられている。
ADMIN_SHUTDOWN_ERROR_CODEを探す。
#define ADMIN_SHUTDOWN_ERROR_CODE "57P01"
ADMIN_SHUTDOWN_ERROR_CODEは57P01のこと。
57P01をgoogleで検索すると以下のWebページがひっかかる。
57P01はadmin_shutdownのこと。

detect_error関数を見てみる。
detect_error(POOL_CONNECTION * backend, char *error_code, int major, char class, bool unread)
{
	int			is_error = 0;
	char		kind;
	int			readlen = 0,
				len;
	static char buf[8192];		/* memory space is large enough */
	char	   *p,
			   *str;

	if (pool_read(backend, &kind, sizeof(kind)))
		return -1;
	readlen += sizeof(kind);
	p = buf;
	memcpy(p, &kind, sizeof(kind));
	p += sizeof(kind);

	ereport(DEBUG5,
			(errmsg("detect error: kind: %c", kind)));


	/* Specified class? */
	if (kind == class)
	{
		/* read actual message */
		if (major == PROTO_MAJOR_V3)
		{
			char	   *e;

			if (pool_read(backend, &len, sizeof(len)) < 0)
				return -1;
			readlen += sizeof(len);
			memcpy(p, &len, sizeof(len));
			p += sizeof(len);

			len = ntohl(len) - 4;
			str = palloc(len);

			pool_read(backend, str, len);
			readlen += len;

			if (readlen >= sizeof(buf))
				ereport(ERROR,
						(errmsg("unable to detect error"),
						 errdetail("not enough space in buffer")));

			memcpy(p, str, len);

			/*
			 * Checks error code which is formatted 'Cxxxxxx' (xxxxxx is error
			 * code).
			 */
			e = str;
			while (*e)
			{
				if (*e == 'C')
				{				/* specified error? */
					is_error = (strcmp(e + 1, error_code) == 0) ? SPECIFIED_ERROR : 0;
					break;
				}
				else
					e = e + strlen(e) + 1;
			}
			pfree(str);
何をしてるのか詳細は分からないですが…、多分、PostgreqSQLのバックエンドから情報を引っ張ってきてエラーだったら「Cxxxxxx」という文字が取得でして、xxxxxxのところにエラーコードが入るのかなと思う。
xxxxxxは今回は57P01が入ってくるのかな…と思う。

以上から、PgpoolはPostgreSQLから57P01を受け取っただけ、と思いました。
その後、PostgreSQLのログを確認し
2019-05-28 04:40:01.414 JST [12646] FATAL:  terminating connection due to administrator command
を発見しました。
※ちなみに、一度、PostgreSQLのログを見たのですが、ログを見逃していて…、Pgpool側の問題かと思ってしまいました。凡ミスです…

スイッチオーバーなのにpg_rewind/pg_basebackupが必要になってしまう

ErogameScapeではpgpoolを使って負荷分散、PostgreSQL障害時の切り替えを実施しています。
PostgreSQLは同期レプリケーションでprimary、standbyの2台構成です。

primaryを正常に停止して(pg_ctl stopして)、standbyを昇格させた(pg_ctl promote)場合、旧primaryはrecovery.confに新primaryを指定して起動すれば、ちゃんとレプリケーションが開始されます。

ところが、pgpoolでfailover_commandとして、
1. 非同期モードに設定を変更(postgresql.confのsynchronous_standby_namesを''にしてreload)
2. standbyを昇格(pg_ctl promote)
というスクリプトを指定し、primaryをpg_ctl stopさせた、旧primaryに適切なrecovery.confを書いて起動させたにも関わらず、レプリケーションが開始出来ず、pg_rewindが必要になってしまいました。

ちゃんとした理由は未だに分からないのですが、おそらく、primaryのpg_ctl stopが完全に終わる前に、pgpoolがstandbyをpg_ctl promoteしてしまうからではないか…と想定しました。
※primaryをちゃんとstopせずに、standbyをpg_ctl promoteすると、経験上、多くの場合で、pg_rewindかpg_basebackupが必要になります。

そこで、failover_commandのスクリプトにsleepを10秒(根拠はありません…)いれてみたら、想定通りスイッチオーバーとしての動作となりました。
以下failover_commandのスクリプトです。
#! /bin/sh -x
# Execute command by failover.
# special values:  %d = node id
#                  %h = host name
#                  %p = port number
#                  %D = database cluster path
#                  %m = new master node id
#                  %M = old master node id
#                  %H = new master node host name
#                  %P = old primary node id
#                  %R = new master database cluster path
#                  %r = new master port number
#                  %% = '%' character

falling_node=$1          # %d
old_primary=$2           # %P
new_primary=$3           # %H
pgdata=$4                # %R
old_hostname=$5          # %h

pghome=/usr/pgsql-11
log=/var/log/pgpool/failover.log

date >> $log
echo "failed_node_id=$falling_node old_primary=$old_primary new_primary=$new_primary old_hostname=$old_hostname UID=$UID" >> $log

if [ $falling_node = $old_primary ]; then
    echo "failed_node_id=master" >> $log
    if [ $UID -eq 0 ]; then
        su postgres -c "ssh -T postgres@$new_primary $pgdata/synchronous_standby_names_change.sh"
        su postgres -c "ssh -T postgres@$new_primary $pghome/bin/pg_ctl reload -D $pgdata"
        sleep 10
        su postgres -c "ssh -T postgres@$new_primary $pghome/bin/pg_ctl promote -D $pgdata"
        su postgres -c "ssh -T postgres@$old_hostname cp -p $pgdata/recovery.conf.for.$old_hostname $pgdata/recovery.conf"
    else
        ssh -T postgres@$new_primary $pgdata/synchronous_standby_names_change.sh
        ssh -T postgres@$new_primary $pghome/bin/pg_ctl reload -D $pgdata
        sleep 10
        ssh -T postgres@$new_primary $pghome/bin/pg_ctl promote -D $pgdata
        ssh -T postgres@$old_hostname cp -p $pgdata/recovery.conf.for.$old_hostname $pgdata/recovery.conf
    fi
    exit 0;
else
    echo "failed_node_id=standby" >> $log
    if [ $UID -eq 0 ]; then
        su postgres -c "ssh -T postgres@$new_primary $pgdata/synchronous_standby_names_change.sh"
        su postgres -c "ssh -T postgres@$new_primary $pghome/bin/pg_ctl reload -D $pgdata"
    else
        ssh -T postgres@$new_primary $pgdata/synchronous_standby_names_change.sh
        ssh -T postgres@$new_primary $pghome/bin/pg_ctl reload -D $pgdata
    fi
fi;
exit 0;
synchronous_standby_names_change.shは、同期レプリケーションを非同期レプリケーションにするために、postgresql.confを書き換えるスクリプトです。
sed -i -e "/synchronous_standby_names/c\#synchronous_standby_names = 'sby'      # standby servers that provide sync rep" /var/lib/pgsql/11/data/postgresql.conf


could not fork new process for connection: Resource temporarily unavailable

PostgreSQLで以下のログを出力した場合、バックエンド・プロセスをforkできていません。
2019-05-26 19:58:26.308 JST [20730] LOG:  could not fork new process for connection: Resource temporarily unavailable
2019-05-26 19:58:27.313 JST [20730] LOG:  could not fork new process for connection: Resource temporarily unavailable
2019-05-26 19:58:27.315 JST [20730] LOG:  could not fork new process for connection: Resource temporarily unavailable
2019-05-26 19:58:28.026 JST [20730] LOG:  could not fork new process for connection: Resource temporarily unavailable
pgpoolを使用している場合、pgpool側では以下のログが出力されます。 ※PostgreSQLへのヘルスチェック機能を有効にしている場合に出力されると思います。
May 26 19:58:27 erogamescape13 pgpool[1696]: [159-1] 2019-05-26 19:58:27: pid 1696: ERROR:  failed to authenticate
May 26 19:58:27 erogamescape13 pgpool[1696]: [159-2] 2019-05-26 19:58:27: pid 1696: DETAIL:  invalid authentication message response type, Expecting 'R' and received 'E'
ヘルスチェックのリトライが指定の回数失敗すると、フェイルバック機能が動きます。
May 26 19:58:28 erogamescape13 pgpool[26104]: [9-1] 2019-05-26 19:58:28: pid 26104: LOG:  health check failed on node 0 (timeout:0)
May 26 19:58:28 erogamescape13 pgpool[26104]: [10-1] 2019-05-26 19:58:28: pid 26104: LOG:  received degenerate backend request for node_id: 0 from pid [26104]
バックエンド・プロセスをfork出来ない理由は、ErogameScapeの場合、プロセス数の上限に達してしまって、プロセスを生成できないことが原因でした。
プロセス数の上限は以下のコマンドで確認可能です。
[root@erogamescape13 ap2]# su - postgres
-bash-4.1$ ulimit -u
1024
postgresユーザーのプロセス上限数が知りたかったので、postgresユーザーでulimitを実行しています。
今、動いているpostmasterのpostgresユーザーのプロセス数の上限を知りたい場合は、まずpostmasterのプロセスIDを調べ
[ap2@erogamescape14 ~]$ ps aux | grep postmaster
ap2       5692  0.0  0.0 103336   900 pts/2    S+   20:45   0:00 grep postmaster
postgres 27012  0.1  0.9 4595684 158676 ?      S    20:11   0:03 /usr/pgsql-11/bin/postmaster -D /var/lib/pgsql/11/data
cat /proc/プロセスID/limitsを見ます。
[root@erogamescape14 ap2]# cat /proc/27012/limits
Limit                     Soft Limit           Hard Limit           Units
Max processes             2048                 63695                processes
Max open files            1024                 4096                 files
ErogameScapeのOSはCentOS6です。
CentOS6のデフォルトのMax processesの上限は1024です。
PostgreSQLのmax_connectionsの数だけ、バックエンドプロセスが生成されれる可能性があります。
ErogameScapeではmax_connectionsを1200に設定しているのですが、いろいろありまして、postgresユーザーのプロセスが1024を超えてしまい、バックエンドプロセスが生成できずcould not fork new process for connectionを出力していました。

Max processesの上限を変更するため、以下の通り/etc/security/limits.d/90-nproc.confを書き換えて、postgreSQLを再起動しました。
※この方法だと他のユーザーも全部書き換わってしまうので…おそらく /etc/init.d/postgresql-11にulimitコマンドで上限を変更するコマンドを追加するのが妥当な気もするのですが、セオリーが分かりませんでした…
# emacs /etc/security/limits.d/90-nproc.conf

- *          soft    nproc     1024
+ *          soft    nproc     2048

watchdog exec interface up/down command failed その2

pgpoolのwatchdog機能をonにし、pgpoolを起動したら、arpingコマンドの実行に失敗したというログが残りました。
[pgpool@erogamescape14 ~]$ /usr/local/pgpool-II-4.0.4/bin/pgpool -d -n > /dev/null 2>&1 &

Apr 27 22:51:46 erogamescape14 pgpool[31446]: [38-1] 2019-04-27 22:51:46: pid 31446: DEBUG:  watchdog exec interface up/down command failed
Apr 27 22:51:46 erogamescape14 pgpool[31446]: [38-2] 2019-04-27 22:51:46: pid 31446: DETAIL:  'sudo arping -U $_IP_$ -w 1' failed. exit status: 2
Apr 27 22:51:46 erogamescape14 pgpool[31446]: [39-1] 2019-04-27 22:51:46: pid 31446: LOG:  failed to acquire the delegate IP address
Apr 27 22:51:46 erogamescape14 pgpool[31446]: [39-2] 2019-04-27 22:51:46: pid 31446: DETAIL:  'if_up_cmd' failed
Apr 27 22:51:46 erogamescape14 pgpool[31446]: [40-1] 2019-04-27 22:51:46: pid 31446: WARNING:  watchdog escalation failed to acquire delegate IP
arpingコマンドを実行した結果は以下のとおりです。
[pgpool@erogamescape14 ~]$ sudo arping -U 192.168.0.101 -w 1
Interface "eth0" is down
ErogameScapeのサーバーはeth0は使用しておらず、eth1だけを使用しています。
[pgpool@erogamescape14 ~]$ ifconfig -a
eth0      Link encap:Ethernet  HWaddr 00:24:8C:FC:29:1E
          BROADCAST MULTICAST  MTU:1500  Metric:1
          RX packets:0 errors:0 dropped:0 overruns:0 frame:0
          TX packets:0 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000
          RX bytes:0 (0.0 b)  TX bytes:0 (0.0 b)
          Interrupt:17

eth1      Link encap:Ethernet  HWaddr 00:1B:21:CE:8C:22
          inet addr:192.168.0.14  Bcast:192.168.0.255  Mask:255.255.255.0
          inet6 addr: fe80::21b:21ff:fece:8c22/64 Scope:Link
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
          RX packets:3514319869 errors:2 dropped:450 overruns:0 frame:2
          TX packets:3390163522 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000
          RX bytes:1709446725964 (1.5 TiB)  TX bytes:1194077098242 (1.0 TiB)
          Interrupt:17 Memory:feae0000-feb00000

lo        Link encap:Local Loopback
          inet addr:127.0.0.1  Mask:255.0.0.0
          inet6 addr: ::1/128 Scope:Host
          UP LOOPBACK RUNNING  MTU:65536  Metric:1
          RX packets:13606420638 errors:0 dropped:0 overruns:0 frame:0
          TX packets:13606420638 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:0
          RX bytes:3248906958354 (2.9 TiB)  TX bytes:3248906958354 (2.9 TiB)
pgpool.confのarping_cmdを以下のように書き換えて解決しました。
arping_cmd = 'sudo arping -U $_IP_$ -w 1'

arping_cmd = 'sudo arping -U $_IP_$ -w 1 -I eth1'
記事検索