[pgpool-general-jp: 1527] Re: pgpoolでエラーが発生します「child process with pid: 28828 was terminated by segmentation fault」

Tatsuo Ishii ishii @ sraoss.co.jp
2018年 4月 7日 (土) 13:52:59 JST


use_watchdog = off

の時のstraceを見せていただけますか?
--
Tatsuo Ishii
SRA OSS, Inc. Japan
English: http://www.sraoss.co.jp/index_en.php
Japanese:http://www.sraoss.co.jp

> お世話になります
> 
> search_primary_node_timeout = 10
> でも同じくpqsl接続できませんでした
> 0 も試しましたが接続できませんでした
> 
> use_watchdog = onのときwatchdogのエラーは
> valgrindのせいかもしれません
> 
> # starce valgrind 〜
> してみたところstarceで
> 11:49:03.852033 open("/bin/ping", O_RDONLY) = 8</usr/bin/ping>
> <0.000027>
> 11:49:03.852108 stat("/bin/ping", {st_mode=S_IFREG|0755,
> st_size=66176, ...}) = 0 <0.000014>
> 11:49:03.852154 getxattr("/bin/ping", "security.capability", NULL, 0)
> = 20 <0.000020>
> 11:49:03.852210 close(8</usr/bin/ping>) = 0 <0.000015>
> 11:49:03.852260 getpid()                = 24084 <0.000012>
> 11:49:03.852298 write(1027</var/lib/pgsql/valgrind-logs.txt>,
> "==24084== \n", 11) = 11 <0.000018>
> 11:49:03.852363 getpid()                = 24084 <0.000012>
> 11:49:03.852401 write(1027</var/lib/pgsql/valgrind-logs.txt>,
> "==24084== Warning: Can't execute setuid/setgid/setcap executable:
> /bin/ping\n", 76) = 76 <0.000015>
> こんなのが出たていたのですが、
> ぐぐってみると
> Valgrind - Users - valgrind "failed: Permission denied" error
> <http://valgrind.10908.n7.nabble.com/valgrind-quot-failed-Permission-denied-quot-error-td33679.html>
> valgrindでsetuidサポートされないみたいです
> ちょっと情報古いかもしれませんが
> 
> use_watchdog = offのときこのエラーはでませんが接続はできません
> 
> valgrindはyumで入れた
> valgrind-3.12.0-9.el7_4.x86_64
> を使用しています
> 
> On 2018/04/05 20:30, Tatsuo Ishii wrote:
>> 理由は分かりませんが、primary nodeの発見に時間がかかっているようです。
>>search_primary_node_timeout = 10
>>などとしてみてはどうでしょう?
>> --
>> Tatsuo Ishii
>> SRA OSS, Inc. Japan
>> English: http://www.sraoss.co.jp/index_en.php
>> Japanese:http://www.sraoss.co.jp
>> 
>>> お世話になります
>>>> ログを見る限り、watchdogの起動に失敗しているようです。watchdogを外して
>>>> 起動してみてはいかがでしょう?(use_watchdog = off)
>>>
>>> use_watchdog = off
>>> は昨日やって見てたんですが、
>>> 同じくpsqlの接続はできませんでした
>>>
>>> pgpoolは
>>> 2018-04-04 16:53:46: pid 6940: LOG: Setting up socket for 0.0.0.0:9999
>>> 2018-04-04 16:53:46: pid 6940: LOG:  Setting up socket for :::9999
>>> 2018-04-04 16:53:47: pid 6940: LOG: pgpool-II successfully
>>> started. version 3.7.2 (amefuriboshi)
>>> 3行だけ出力でした
>>>
>>> On 2018/04/05 19:15, Tatsuo Ishii wrote:
>>>>> お世話になります
>>>>>
>>>>>> サンプルのクエリを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 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 メーリングリストの案内