[pgpool-general-jp: 1523] Re: pgpoolでエラーが発生します「child process with pid: 28828 was terminated by segmentation fault」
Tatsuo Ishii
ishii ＠ sraoss.co.jp
2018年 4月 5日 (木) 19:15:41 JST
> お世話になります
>
>> サンプルのクエリをCakePHPから単独で実行して落ちなければ、
>
> CakePHPから単独のSQLを実行してみました
> エラーは起きず、テーブル書き込み可能でした
>
>> valgrindをかけた状態
>> でpgpoolを実行すれば、何かわかると思います。
>
> valgrindを使ったことが無かったので、
> 具体的にはどうすればよいのでしょうか
>
> pgpoolはsystemctl start pgpool.serviceで起動しています
> service内容を調べて同じように起動するコマンドを作りました
> /etc/pgpool-II/pgpool.confをコピーして
> pid_file_name
> memqcache_oiddir
> だけユーザーディレクトリに変えました
>
> /usr/bin/valgrind --trace-children=yes --track-origins=yes
> --log-file=/var/lib/pgsql/valgrind-logs.txt --leak-check=full
> --show-leak-kinds=all /usr/bin/pgpool -f /var/lib/pgsql/pgpool.conf -n
>> /var/lib/pgsql/pgpool-logs.txt 2>&1
>
> 以上のコマンドを実行しましたが、
> psqlで接続が出来ません
> 以下のようになります
>
> psql -U postgres -h 192.168.100.199 -p 9999 test2
> psql: could not connect to server: No route to host
> Is the server running on host "192.168.100.199" and accepting
> TCP/IP connections on port 9999?
>
> psをみると
> root 8742 0.1 2.6 294316 159324 pts/0 S+ 17:49 0:00 /usr/bin/valgrind
> --trace-children=yes --track-origins=yes
> --log-file=/var/lib/pgsql/valgrind-logs.txt --leak-check=full
> --show-leak-kinds=all /usr/bin/pgpool -f /var/lib/pgsql/pgpool.conf -n
> はたくさんあるのですが、
> pgpool自体は起動出来てないのでしょうか？
いや、それで問題ないです。
こちらでもvalgrindを使ってPgpool-IIを起動していますが、特に問題なく動いています。
ログを見る限り、watchdogの起動に失敗しているようです。watchdogを外して
起動してみてはいかがでしょう？(use_watchdog = off)
> valgrindだけはずして
> /usr/bin/pgpool -f /var/lib/pgsql/pgpool.conf -n >
> /var/lib/pgsql/pgpool-logs.txt 2>&1
> 実行した場合は
> psqlで接続できました
>
> どうするのが正しいのでしょうか
> 教えていただけると助かります
>
> どうぞよろしくお願いします。
>
> ---------------
>
> 以下valgrindを実行したときの表示です
> Permissionのエラーがでましたので、
> ユーザーをpostgresやrootにしてみましたが、
> 上と同様にpsqlで接続できませんでした
>
> 2018-04-04 16:40:46: pid 6557: LOG: Backend status file
> /tmp/pgpool_status does not exist
> 2018-04-04 16:40:46: pid 6557: LOG: waiting for watchdog to initialize
> 2018-04-04 16:40:46: pid 6558: LOG: setting the local watchdog node
> name to "192.168.100.154:9999 Linux m-yydb"
> 2018-04-04 16:40:46: pid 6558: LOG: watchdog cluster is configured
> with 1 remote nodes
> 2018-04-04 16:40:46: pid 6558: LOG: watchdog remote node:0 on
> 192.168.100.180:9000
> 2018-04-04 16:40:46: pid 6558: LOG: interface monitoring is disabled
> in watchdog
> 2018-04-04 16:40:46: pid 6558: LOG: watchdog node state changed from
> [DEAD] to [LOADING]
> 2018-04-04 16:40:51: pid 6558: LOG: watchdog node state changed from
> [LOADING] to [JOINING]
> 2018-04-04 16:40:55: pid 6558: LOG: watchdog node state changed from
> [JOINING] to [INITIALIZING]
> 2018-04-04 16:40:56: pid 6558: LOG: I am the only alive node in the
> watchdog cluster
> 2018-04-04 16:40:56: pid 6558: HINT: skipping stand for coordinator
> state
> 2018-04-04 16:40:56: pid 6558: LOG: watchdog node state changed from
> [INITIALIZING] to [MASTER]
> 2018-04-04 16:40:56: pid 6558: LOG: I am announcing my self as
> master/coordinator watchdog node
> 2018-04-04 16:41:00: pid 6558: LOG: I am the cluster leader node
> 2018-04-04 16:41:00: pid 6558: DETAIL: our declare coordinator message
> is accepted by all nodes
> 2018-04-04 16:41:00: pid 6558: LOG: setting the local node
> "192.168.100.154:9999 Linux m-yydb" as watchdog cluster master
> 2018-04-04 16:41:00: pid 6558: LOG: I am the cluster leader
> node. Starting escalation process
> 2018-04-04 16:41:00: pid 6557: LOG: watchdog process is initialized
> 2018-04-04 16:41:00: pid 6558: LOG: escalation process started with
> PID:6573
> 2018-04-04 16:41:00: pid 6573: LOG: watchdog: escalation started
> 2018-04-04 16:41:00: pid 6558: LOG: new IPC connection received
> 2018-04-04 16:41:00: pid 6558: LOG: new IPC connection received
> 2018-04-04 16:41:01: pid 6574: LOG: 2 watchdog nodes are configured
> for lifecheck
> 2018-04-04 16:41:01: pid 6574: LOG: watchdog nodes ID:0
> Name:"192.168.100.154:9999 Linux m-yydb"
> 2018-04-04 16:41:01: pid 6574: DETAIL: Host:"192.168.100.154" WD
> Port:9000 pgpool-II port:9999
> 2018-04-04 16:41:01: pid 6574: LOG: watchdog nodes ID:1 Name:"Not_Set"
> 2018-04-04 16:41:01: pid 6574: DETAIL: Host:"192.168.100.180" WD
> Port:9000 pgpool-II port:9999
> 2018-04-04 16:41:01: pid 6557: LOG: Setting up socket for 0.0.0.0:9999
> 2018-04-04 16:41:01: pid 6557: LOG: Setting up socket for :::9999
> 2018-04-04 16:41:01: pid 6588: FATAL: watchdog failed to ping
> host"192.168.100.199"
> 2018-04-04 16:41:01: pid 6588: DETAIL: execv(/bin/ping)
> failed. reason: Permission denied
> 2018-04-04 16:41:01: pid 6573: WARNING: watchdog failed to ping
> host"192.168.100.199"
> 2018-04-04 16:41:01: pid 6573: DETAIL: ping process exits with code: 1
> 2018-04-04 16:41:01: pid 6573: LOG: waiting for the delegate IP
> address to become active
> 2018-04-04 16:41:01: pid 6573: DETAIL: waiting... count: 1
> 2018-04-04 16:41:01: pid 6632: FATAL: watchdog failed to ping
> host"192.168.100.199"
> 2018-04-04 16:41:01: pid 6632: DETAIL: execv(/bin/ping)
> failed. reason: Permission denied
> 2018-04-04 16:41:02: pid 6557: LOG: pgpool-II successfully
> started. version 3.7.2 (amefuriboshi)
> 2018-04-04 16:41:02: pid 6573: WARNING: watchdog failed to ping
> host"192.168.100.199"
> 2018-04-04 16:41:02: pid 6573: DETAIL: ping process exits with code: 1
> 2018-04-04 16:41:02: pid 6573: LOG: waiting for the delegate IP
> address to become active
> 2018-04-04 16:41:02: pid 6573: DETAIL: waiting... count: 2
> 2018-04-04 16:41:02: pid 6649: FATAL: watchdog failed to ping
> host"192.168.100.199"
> 2018-04-04 16:41:02: pid 6649: DETAIL: execv(/bin/ping)
> failed. reason: Permission denied
> 2018-04-04 16:41:02: pid 6577: LOG: set SO_REUSEPORT option to the
> socket
> 2018-04-04 16:41:02: pid 6577: LOG: creating watchdog heartbeat
> receive socket.
> 2018-04-04 16:41:02: pid 6577: DETAIL: set SO_REUSEPORT
> 2018-04-04 16:41:02: pid 6578: LOG: set SO_REUSEPORT option to the
> socket
> 2018-04-04 16:41:02: pid 6578: LOG: creating socket for sending
> heartbeat
> 2018-04-04 16:41:02: pid 6578: DETAIL: set SO_REUSEPORT
> 2018-04-04 16:41:02: pid 6573: WARNING: watchdog failed to ping
> host"192.168.100.199"
> 2018-04-04 16:41:02: pid 6573: DETAIL: ping process exits with code: 1
> 2018-04-04 16:41:02: pid 6573: LOG: waiting for the delegate IP
> address to become active
> 2018-04-04 16:41:02: pid 6573: DETAIL: waiting... count: 3
> 2018-04-04 16:41:02: pid 6573: LOG: failed to acquire the delegate IP
> address
> 2018-04-04 16:41:02: pid 6573: DETAIL: 'if_up_cmd' failed
> 2018-04-04 16:41:02: pid 6573: WARNING: watchdog escalation failed to
> acquire delegate IP
> 2018-04-04 16:41:02: pid 6558: LOG: watchdog escalation process with
> pid: 6573 exit with SUCCESS.
> -------------------------
>
> On 2018/04/03 18:10, Tatsuo Ishii wrote:
>> 石井です。
>>CakePHPはおそらく無関係だと思います。
>>サンプルのクエリをCakePHPから単独で実行して落ちなければ、それまでに実
>> 行されたクエリのどれかがメモリを壊している可能性があります。
>>落ちている箇所がシステムのライブラリなので、それがバグを持っている可能
>> 性は一応排除して良いと思うので)。Pgpool-IIの未知のバグを踏んだ、という
>> ことですね。メモリを壊しているということであれば、valgrindをかけた状態
>> でpgpoolを実行すれば、何かわかると思います。
>> --
>> Tatsuo Ishii
>> SRA OSS, Inc. Japan
>> English: http://www.sraoss.co.jp/index_en.php
>> Japanese:http://www.sraoss.co.jp
>>
>>> 調査ありがとうございます
>>> CakePHPのORMのなにかが原因なんでしょうか
>>> アプリの方で回避する方法がないか探ってみます
>>>
>>> On 2018/04/03 17:47, Tatsuo Ishii wrote:
>>>> 石井です。
>>>>
>>>>> psql(pgadmin)から実行ではエラーは出ませんでした
>>>>> 以下実行したSQLです
>>>> いただいたSQLを拡張クエリモードで実行してみましたが、特に問題ありませ
>>>> んでした。
>>>> 使用クライアントはpgprotoです。
>>>> https://github.com/tatsuo-ishii/pgproto
>>>> 参考までに、使用したpgprotoのデータファイルを添付しておきます。
>>>> --
>>>> Tatsuo Ishii
>>>> SRA OSS, Inc. Japan
>>>> English: http://www.sraoss.co.jp/index_en.php
>>>> Japanese:http://www.sraoss.co.jp
>>>>
>>>
>>> _______________________________________________
>>> pgpool-general-jp mailing list
>>> pgpool-general-jp ＠ sraoss.jp
>>> http://www.sraoss.jp/mailman/listinfo/pgpool-general-jp
>
> _______________________________________________
> pgpool-general-jp mailing list
> pgpool-general-jp ＠ sraoss.jp
> http://www.sraoss.jp/mailman/listinfo/pgpool-general-jp
pgpool-general-jp メーリングリストの案内