2019年04月

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'

watchdog exec interface up/down command failed その1

[環境]
pgpool-4.0.4

[現象]
pgpoolの起動時に-nオプションをつけないと、if_up_cmdが失敗する

[原因]
分かりません…、私のやり方が悪いのか、バグなのかすら分からないので、あまりよろしくないのですが、とりあえず-nをつけて起動することにします。

[詳細]
pgpoolはWatchdog機能をONにすると、冗長構成をとることができます。
いろいろ設定し、pgpoolを-nオプションなしで立ち上げた場合、if_up_cmd、pgpoolのための仮想IPアドレスをIFに追加するコマンドが失敗します。
デバッグモードで立ち上げてもなぜ失敗しているかの記録がないのでなぜ失敗するのか分かりません。
[pgpool@erogamescape14 ~]$ /usr/local/pgpool-II-4.0.4/bin/pgpool -d

Apr 27 22:49:21 erogamescape14 [29985]: [37-1] 2019-04-27 22:49:21: pid 29985: DEBUG:  watchdog exec interface up/down command failed
Apr 27 22:49:21 erogamescape14 [29985]: [37-2] 2019-04-27 22:49:21: pid 29985: DETAIL:  'sudo ip addr add $_IP_$/24 dev eth1 label eth1:0' failed. exit status: 1
Apr 27 22:49:21 erogamescape14 [29985]: [38-1] 2019-04-27 22:49:21: pid 29985: LOG:  failed to acquire the delegate IP address
Apr 27 22:49:21 erogamescape14 [29985]: [38-2] 2019-04-27 22:49:21: pid 29985: DETAIL:  'if_up_cmd' failed
Apr 27 22:49:21 erogamescape14 [29985]: [39-1] 2019-04-27 22:49:21: pid 29985: WARNING:  watchdog escalation failed to acquire delegate IP
-nオプションをつけると、成功します。
[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]: [37-1] 2019-04-27 22:51:46: pid 31446: DEBUG:  watchdog exec interface up/down command: 'sudo ip addr add $_IP_$/24 dev eth1 label eth1:0' succeeded

理由はわからないですが、-nをつけてpgpoolを起動することにしました。
pgpoolの

FATAL: could not connect to the primary server: invalid connection option "target_session_attrs"

ErogameScapeでは、2019/04/28時点で、PostgreSQL9.6で動いています。
自宅サーバーは2台でpgpoolのネイティブレプリケーションモードを使用してデータベースの同期をとり、PostgreSQLのストリーミングレプリケーション機能を使ってさくらインターネットの専用サーバーに非同期でデータベースの同期をとっています。

PostgreSQL9.6のEOLは2021年9月で、まだ時間はありますが、pgpoolのネイティブレプリケーション機能をやめて、自宅サーバーもPostgreSQLのストリーミングレプリケーション機能を使用するようにし、pgpoolをMASTER/SLAVE構成にし、PostgreSQLも11へVerUPするため、検証を開始しました。

原因が何年もつかめていないので放置しているのですが…しばしばpgpoolがPostgreSQLがdownしたと勘違いすることがあります。
原因を探るのを諦めて、その都度リカバリすることにしています。
いつも通り、pg_basebackupを実行し、スタンバイのpostgresqlを起動したところ以下のメッセージがでて、リカバリが出来ませんでした。
< 2019-04-26 10:49:53.255 JST > LOG:  database system was interrupted; last known up at 2019-04-26 09:57:15 JST
< 2019-04-26 10:49:53.694 JST > LOG:  entering standby mode
< 2019-04-26 10:49:53.795 JST > LOG:  redo starts at 265/C500C050
< 2019-04-26 10:49:57.545 JST > LOG:  consistent recovery state reached at 265/DCA9DF80
< 2019-04-26 10:49:57.546 JST > LOG:  database system is ready to accept read only connections
< 2019-04-26 10:49:57.679 JST > FATAL:  could not connect to the primary server: invalid connection option "target_session_attrs"
recovery.confを確認したところ、PostgreSQL9.6のpg_basebackupの--write-recovery-confで生成されるrecovery.confとPostgreSQL11のpg_basebackupの--write-recovery-confで生成されるrecovery.confに差異がありました。

PostgreSQL9.6
primary_conninfo = 'user=replication_user password=**** host=**** port=5432 sslmode=prefer sslcompression=1 krbsrvname=postgres'
PostgreSQL11
primary_conninfo = 'user=replication_user password=**** host=**** port=5432 sslmode=prefer sslcompression=0 krbsrvname=postgres target_session_attrs=any'
target_session_attrsというパラメータがPostgresql10で追加されています。
target_session_attrs=anyを消して、postgresqlを起動し、レプリケーションが開始されました。
[root@localhost ap2]# which pg_basebackup
/usr/bin/pg_basebackup
[root@localhost ap2]# ls -l /usr/bin/pg_basebackup
lrwxrwxrwx 1 root root 37  4月 24 10:35 2019 /usr/bin/pg_basebackup -> /etc/alternatives/pgsql-pg_basebackup
[root@localhost ap2]# ls -l /etc/alternatives/pgsql-pg_basebackup
lrwxrwxrwx 1 root root 31  4月 24 10:35 2019 /etc/alternatives/pgsql-pg_basebackup -> /usr/pgsql-11/bin/pg_basebackup
となっているので、今後は/usr/pgsql-9.6/bin/pg_basebackupと絶対パスで指定して実行するようにしました。

pcp_attach_node: invalid option -- 'p'

ErogameScapeの現用サーバーにpgpool-4.0.4をソースからインストールして、pcp_attach_nodeを実行したところ以下のように、-pオプションはないと表示されました。
[ap2@erogamescape14 ~]$ pcp_attach_node -p 8898 -U pgpool 1
pcp_attach_node: invalid option -- 'p'
pcp_attach_node - attach a node from pgpool-II

Usage: pcp_attach_node [-d] timeout hostname port# username password nodeID
Usage: pcp_attach_node -h

  -d       - enable debug message (optional)
  timeout  - connection timeout value in seconds. command exits on timeout
  hostname - pgpool-II hostname
  port#    - pgpool-II port number
  username - username for PCP authentication
  password - password for PCP authentication
  nodeID   - ID of a node to be attached
  -h       - print this help
テストサーバーでは問題なく動いていたので、現用サーバーの問題だと思いました。
そこで「どのpcp_attach_nodeを実行しているか」を確認しました。
[ap2@erogamescape14 ~]$ which pcp_attach_node
/usr/local/bin/pcp_attach_node
ErogameScapeはpgpoolを追える範囲では2.3.3の頃から使っていて、いろいろなverのpcp_attach_nodeが格納されています。
[root@erogamescape14 pgpool]# find / -name pcp_attach_node
中略
/usr/local/pgpool-II-3.5.1/bin/pcp_attach_node
/usr/local/pgpool-II-3.6.0/bin/pcp_attach_node
/usr/local/pgpool-II-3.3.1/bin/pcp_attach_node
/usr/local/pgpool-II-4.0.4/bin/pcp_attach_node
/usr/local/bin/pcp_attach_node
/usr/local/bin/pcp_attach_nodeがいったいいつのverのpcp_attach_nodeなのか分かりません…
[ap2@erogamescape14 ~]$ /usr/local/pgpool-II-4.0.4/bin/pcp_attach_node -p 8898 -U pgpool 1
と実行して、ちゃんと動きました。

unix_socket_directories

PostgreSQLのpostgresql.confのunix_socket_directoriesはUnixドメインソケットのディレクトリを指定します。 カンマ区切りでディレクトリを複数指定できます。 CentOSにrpmでPostgreSQLをインストールした場合、デフォルトの設定では /tmp /var/run/postgresql の2つのディレクトリ配下にUnixドメインソケットが生成されます。
$ cat /etc/redhat-release
CentOS release 6.10 (Final)

$ ls -la /var/run/postgresql
合計 12
drwxr-xr-x   2 postgres postgres 4096  4月 25 20:19 2019 .
drwxr-xr-x. 27 root     root     4096  4月 25 20:20 2019 ..
srwxrwxrwx   1 postgres postgres    0  4月 25 20:08 2019 .s.PGSQL.5432
-rw-------   1 postgres postgres   66  4月 25 20:08 2019 .s.PGSQL.5432.lock

$ ls -la /tmp | grep PGSQL
srwxrwxrwx   1 postgres postgres       0  4月 25 21:08 2019 .s.PGSQL.5432
-rw-------   1 postgres postgres      51  4月 25 21:08 2019 .s.PGSQL.5432.lock

# cat /var/lib/pgsql/11/data/postgresql.conf | grep unix_socket_directories
#unix_socket_directories = '/var/run/postgresql, /tmp'  # comma-separated list of directories

unix_socket_directories (string)
サーバがクライアントアプリケーションからの接続要求を監視するUnixドメインソケットのディレクトリを指定します。 複数ソケットはコンマで区切られた複数ディレクトリをリストすることで作成できます。
中略
デフォルト値は通常/tmpですが、ビルド時に変更できます。

複数設定できた方がいい理由が思いつかないのですが、たぶん、いいことがあるのでしょう。
以下のように、どちらのUnixドメインソケットを利用しても接続できます。
[ap2@localhost ~]$ psql -h /tmp -p 5432
psql (11.2)
"help" でヘルプを表示します。

ap2=# \q
[ap2@localhost ~]$ psql -h /var/run/postgresql -p 5432
psql (11.2)
"help" でヘルプを表示します。

ap2=# \q

pg_dumpallがcanceling statement due to conflict with recoveryで失敗する

ErogameScapeのPostgreSQLを9.6系から11系にあげるため、検証用の環境を構築します。
検証用環境のPostgreSQL11にデータを流し込むためのデータを現用のPostgreSQLからデータをまるごと引き抜きます。
データをまるごと引き抜く場合はpg_dumpallコマンドを使います。

pg_dumpallは非同期レプリケーションのスタンバイ側のサーバーで実行しました。
pg_dumpallを実行したところ以下のエラーが発生しました。
$ pg_dumpall -f zenbu_all_20190422_9.6.sql
pg_dump: テーブル"userreview"の内容のダンプに失敗: PQgetResult()が失敗しました。
pg_dump: サーバのエラーメッセージ: ERROR:  canceling statement due to conflict with recovery
DETAIL:  User query might have needed to see row versions that must be removed.
pg_dump: 次のコマンドでした: COPY public.userreview (game, uid, tokuten, tourokubi, hitokoto, memo, netabare, id, giveup, possession, play, reserve, outline, before_hitokoto, before_tokuten, before_tourokubi, outline_hitokoto, display, play_tourokubi, outline_netabare, outline_tourokubi, display_unique_count, sage, before_purchase_will, before_sage, total_play_time, time_before_understanding_fun, okazu_tokuten, trial_version_hitokoto, trial_version_hitokoto_sage, trial_version_hitokoto_tourokubi, "timestamp", modified) TO stdout;
pg_dumpall: データベース"ap2"に対するpg_dumpが失敗しました。終了します
pg_dumpallにしている最中にマスタ側でuserreviewテーブルで更新/削除があって、コンフリクトして、pg_dumpallが失敗したのだと想定します。
スタンバイ側で一時WALを反映しないようにしてから、pg_dumpallを実行し、pg_dumpallが終了したらWALを反映するようにすればいいと思いました。
WALを反映しないでスタンバイを立ち上げる良い方法が思いつかなかったので、recovery.confにおいて、primary_conninfoのポートを使っていないポートに書き換えて、PostgreSQLを立ち上げました。
$ emacs /var/lib/pgsql/9.6/data/recovery.conf
以下のように書き換え。
primary_conninfo = 'user=replication_user password=**** host=**** port=1000 sslmode=prefer sslcompression=1 krbsrvname=postgres'
PostgreSQLを再起動。
# /sbin/service postgresql-9.6 restart
この後、pg_dumpallを実行してバックアップを取得した後、recovery.confを元の設定に書き換えて、PostgtreSQLを再起動し、無事、非同期レプリケーションのスタンバイ側として組み込まれました。

記事検索