MySQL server has gone away [begin;]のエラーについて
いつもお世話になっております。
表記の件について知恵を貸して頂きたく。
事象としては、サーバ状態が正常にもかかわらず、
ICMP PINGがDOWN状態になってしまうというものです。
確認したところ以下のログが出ておりました。
■zabbix_server.log(※ホスト名は置き換えております。)
------------------------------------------------------------------------------------------------------------------------------------------------------------------------
20160203:150834 Zabbix agent item "vm.memory.size[buffers]" on host "HOST01" failed: first network error, wait for 15 seconds
20160203:150849 Zabbix agent item "vm.memory.size[total]" on host "HOST02" failed: first network error, wait for 15 seconds
20160203:150849 Zabbix agent item "proc.num[,,run]" on host "HOST03" failed: first network error, wait for 15 seconds
20160203:150849 Zabbix agent item "vfs.fs.size[/boot,pfree]" on host "HOST004" failed: first network error, wait for 15 seconds
20160203:150849 Zabbix agent item "vfs.fs.size[/,pfree]" on host "HOST005" failed: first network error, wait for 15 seconds
20160203:150850 [Z3005] query failed: [2006] MySQL server has gone away [begin;]
20160203:150850 resuming Zabbix agent checks on host "HOST01": connection restored
20160203:150904 resuming Zabbix agent checks on host "HOST02": connection restored
20160203:150904 resuming Zabbix agent checks on host "HOST03": connection restored
20160203:150904 resuming Zabbix agent checks on host "HOST04": connection restored
20160203:150904 resuming Zabbix agent checks on host "HOST05": connection restored
------------------------------------------------------------------------------------------------------------------------------------------------------------------------
■zabbix_server.logにエラーが出ていた、HOST1のzabbix_agentd.log(※サーバIPは置き換えております。)
------------------------------------------------------------------------------------------------------------------------------------------------------------------------
20160202:150509 active check configuration update from [ZabbixサーバIP:10051] started to fail (cannot connect to [[ZabbixサーバIP]:10051]: [4] Interrupted system call)
20160202:150512 active check data upload to [ZabbixサーバIP:10051] started to fail ([connect] cannot connect to [[ZabbixサーバIP]:10051]: [4] Interrupted system call)
20160202:150515 active check data upload to [ZabbixサーバIP:10051] is working again
20160202:150609 active check configuration update from [ZabbixサーバIP:10051] is working again
20160204:150520 active check data upload to [ZabbixサーバIP:10051] started to fail ([connect] cannot connect to [[ZabbixサーバIP]:10051]: [4] Interrupted system call)
20160204:150522 active check data upload to [ZabbixサーバIP:10051] is working again
------------------------------------------------------------------------------------------------------------------------------------------------------------------------
フォーラムから確認したところ、
どうやらアクティブチェックにてタイムアウトが発生しログが出ていたようです。
ここで分からないのが、
ICMP PINGのエラーが出ていないことです。
上記にエラーに引きずられてICMP PINGも取れなくなることがあるのでしょうか？
fripper - 投稿数: 495
zabbix_server が稼働している「サーバ」
zabbix_agentd が稼働している「監視対象ホスト (HOST01 / HOST02 / HOST03 / HOST04 / HOST05)」
のホストが存在することはログから読み取れました
★サーバ側ログについて
サーバ側のログより、02/03 15:08:34 から 02/03 15:08:49 に、(HOST01、HOST02、HOST03、HOST04、HOST05) に設定されている
「Zabbix エージェント」タイプのアイテムが「first network error」で取得不可になっているのが判ります
「Zabbixエージェント」タイプのアイテムは、サーバ側から、対象のエージェントに問い合わせて値を得るので
サーバ→エージェント方向で、ネットワークの疎通が途絶えたなど、何らかの通信不良があったのではと思います
その直後、02/03 15:08:50 に、DBへの接続エラーを示すログ
MySQLを、zabbix_server が稼働しているサーバと同じサーバ上に置いているか、
別のサーバに置いているかが解らないのですが、上の事象（エージェント取得エラー）から推測すると、
別のサーバ上に置かれていて、そのDBとの疎通も途絶えたのではないかと推測します
DB の設置場所はどうなっていますか？
さらにその後、02/03 15:08:50 から 15:09:04 にかけて、(HOST01、HOST02、HOST03、HOST04、HOST05) に設定されている
「Zabbix エージェント」タイプのアイテムの取得を試行したところ成功し、「connection restored」として復旧したのだと思います
サーバ側ホストの出口となる部分に近いところで、何らかのネットワーク障害があったように読み取れました
★エージェント側ログについて
エージェント側のログについては、時間帯も一致していないので、上記サーバ側のログとは
事象・原因ともに異なるのではないでしょうか？
2016/02/02 15:05:09 に、エージェント側からサーバへ向けて「Zabbixエージェント（アクティブ）」のアイテム項目リストを取りにいったが
「Interrupted system call」エラーで失敗した
02/02 15:05:12 には、エージェント側からサーバへ向けて「Zabbixエージェント（アクティブ）」で収集した結果を送ろうとして失敗
15:05:15 に、おそらくリトライして、送信成功して「working again」
15:06:09 に、先ほど失敗していた「Zabbixエージェント（アクティブ）」のアイテム項目リストを取りにいって、成功した
02/04 15:05:20 に、エージェント側からサーバへ向けて「Zabbixエージェント（アクティブ）」で収集した結果を送ろうとして 02/02 15:05:12 と同じように失敗
02/04 15:05:22 に、おそらくリトライして、送信成功して「working again」
前述の「サーバ側出口付近のネットワーク障害」と同じような事象が、02/02と02/04 にもあり、
そちらが原因となって、エージェント側からサーバへ向けての疎通がとれなくなっていたのではないでしょうか？
★タイムアウトについて
＞どうやらアクティブチェックにてタイムアウトが発生しログが出ていたようです。
ログを参照している限りは、タイムアウトらしき事象は感じられませんが‥
＃よろしければ、参考にされたフォーラム書込をお教え戴けますか？
★ icmp ping について
＞ここで分からないのが、
＞ICMP PINGのエラーが出ていないことです。
上記の推測「サーバ側出口付近のネットワーク障害」が合っているとして‥
icmpping のアイテムが各ホストに設定されていて、
「たまたま障害のあったタイミングに、サーバがicmpping 項目のデータを収集していれば」
エラーが検知されたかもしれません
提示されたログを見ている限り、通信が不安定になっているのは「ほんの数秒間」のようなので、
たまたまそのタイミングに icmpping の実行が重ならない限り、エラーが検知できないと思います
kaeru - 投稿数: 264
>fripper様
ご回答ありがとうございます。
迅速なご回答を頂いたのにご返信が出来ておらず申し訳ありません。
また、考えがまとまらない内から質問を投げてしまったため、
分かりにくい質問となり申し訳ありませんでした。
>★サーバ側ログについて
MySQLはzabbix_serverと同じサーバで稼働させております。
ZabbixServer自体のパラメータは全て取得出来ておりました。
「監視対象ホスト (HOST01 / HOST02 / HOST03 / HOST04 / HOST05)」については
監視サーバとは別のFW配下に存在します。
上記のため、別FWの接続に何か問題がありエラーが出たと推測しました。
Mysqlについては仕様確認中ですが、
通信が行えずアイテムが取得出来ないため、
何かしらのタイムアウト閾値（ZabbixサーバのTimeout?AgentのTimeout?）に引っかかり
Mysqlの接続を再試行したと思われます。
>★エージェント側ログについて
すみません。ご指摘の通りログが一致しておりません。
これ以降にも発生したため確認したところ、
監視サーバ側では取得不可のログが出ているのに、
非監視サーバ側ではログが出ていないことが確認出来ました。
#恐らくアイテムの取得タイミングの問題
「サーバ側出口付近のネットワーク障害」は恐らくは
ZabbixServerとAgentの間に挟んでいるFWと辺りが付きました。
>★タイムアウトについて
参考URLを添付したつもりが、タグで囲んだせいで表示されておりませんでした。
http://www.zabbix.jp/node/3209
http://www.zabbix.jp/node/2370
当初イメージとしてはZabbix設定が悪く、各ZabbixAgentアイテムの取得に失敗し、
その余波でシンプルチェックのICMP Pingが取れなくなるのではないか…と思いましたが、
Zabbix設定ではなくインフラ面の可能性が高そうです。
>★ icmp ping について
こちらは私の勘違いです。申し訳ありません。
詳しく記載が出来ていなかったのですが、
Pingの疎通確認は「Template ICMP Ping」を使用しております。
監視サーバがPINGを打って応答が無かった場合、
何かしらZabbixServer.logにエラーが出るかと思っていたのですが、
テストをしたところ、そもそもシンプルチェックのため
値が取れなかったらエラーなど出ずにDown（0）で検知しておりました。
上記からICMP PING云々の前にご指摘通り
間に挟まっているFWに起因する問題かと思われます。
一先ずは本当にインフラの問題か切り分けのため、
監視サーバから手打ちでPINGを流し、
Zabbixが取得したPINGと同じ結果になるかを確認し、
同じ結果になるようであればインフラ側の調査を進めます。
#今更で申し訳ありませんが、
Zabbixバージョンは2.2.4になります。
fripper - 投稿数: 495
kaeru様
>★サーバ側ログについて
>Mysqlについては仕様確認中ですが、
>通信が行えずアイテムが取得出来ないため、
>何かしらのタイムアウト閾値（ZabbixサーバのTimeout?AgentのTimeout?）に引っかかり
>Mysqlの接続を再試行したと思われます。
>[Z3005] query failed: [2006] MySQL server has gone away [begin;]
MySQL切断のエラーメッセージについてですが、Server/Agent のTimeout 設定等は関係なく
MySQL 側の接続・無操作タイムアウトによるものです
デフォルトでは8時間になっているようです
MySQL に関する参考記事 ： http://fkaz.net/tech/server/linux/80/
切断現象に関する参考記事として記載戴いたフォーラムスレッドのうち
http://www.zabbix.jp/node/3209 の中
http://www.zabbix.jp/node/3209/8978 KAZ 様の書込にあるとおりです
切断発生のメッセージが記録されていることには大きな問題はなく、エラー発生時にログ記録され、
自動的に再接続されるようです
当該のログ行に、関連するzabbix_serverプロセスのPIDが記載されており、そのPID値と、
zabbix_server 起動時にログ記録されるPID・プロセス役割の記録をもとに、対応関係を見れば
どのプロセスがタイムアウトによる切断になったかが、判るかと思います
>★エージェント側ログについて
>監視サーバ側では取得不可のログが出ているのに、
>非監視サーバ側ではログが出ていないことが確認出来ました。
「Zabbixエージェント」タイプのアイテムの場合、サーバからエージェントへ問い合わせされるので、
サーバからエージェントまで要求の通信が到達せず、エージェント側には記録が残らなかったのだと思います
kaeru - 投稿数: 264
>fripper様
フォローありがとうございます。
Mysqlの設定を確認しましたが、
弄った記憶が無いのでデフォルト8時間のままでした。
ただ値が8時間なのに1分値が取れないだけでメッセージが出るので
Zabbix側で通信が行えなかったのでセッション切れと判定して
再接続しているようです。（現在、wait for 15 secondsがどこから出てきたのが確認しております）
MySQL server has gone away [begin;]については出てくるのは使用ですが、
どちらかというとその前に値が取れずにセッションが切れることが問題と認識しました。
（間違っていたらすみません…。）
>「Zabbixエージェント」タイプのアイテムの場合、サーバからエージェントへ問い合わせされるので、
>サーバからエージェントまで要求の通信が到達せず、エージェント側には記録が残らなかったのだと思います
PIDの関係を確認したところ、乗っているものと乗っていないものがありました。
こちらは通信が届いたがタイムアウトした、通信も届かなくてタイムアウトした…の違いかと思います。
その後、調査を進めてインフラ側にてPINGを定期的に流すシェルを作成し
経過を見たところ、値が取れない該当時間帯の数十秒間でレスポンスが極端に悪くなっておりました。
サーバ側では何も処理をしていないことが確認をとれたためインフラ側が濃厚になりました。
自分が構築したZabbixが不安満点だったので盲目的にZabbix側から調査に入ってしまいました…。
大局的な視点で切り分け出来るよう留意します。
fripper - 投稿数: 495
kaeru 様
>20160203:150834 Zabbix agent item "vm.memory.size[buffers]" on host "HOST01" failed: first network error, wait for 15 seconds
> ...
>20160203:150850 resuming Zabbix agent checks on host "HOST01": connection restored
エージェントからの値取得でネットワーク接続などに失敗した場合、同エージェントに存在する別のアイテムでも同じ失敗が起こる可能性が
高いため、同ホストに設定されているエージェント系アイテムが、一括して一定時間だけ取得保留される仕様になっています
wait for 15 seconds の時間について‥
zabbix_server.conf の Timeout 設定に設定されている時間だけ待った結果、ダメだったと判定された場合の、
ホスト一時無効化・リトライまでの時間間隔
# UnreachableDelay=15
zabbix_server.conf のこの項目です
> ただ値が8時間なのに1分値が取れないだけでメッセージが出るので
> Zabbix側で通信が行えなかったのでセッション切れと判定して
> 再接続しているようです。
こちらのMySQL のタイムアウト gone away エラーは、アイテム取得に関するタイムアウトエラーとは全く無関係です
zabbix_server 内では、アイテム取得結果のDB保存だけでなく、設定情報の読込や、不要データの消去(HouseKeeper)等、
さまざまな用途でそれぞれDB接続しているので、それらのうちいずれかが、DB接続・DB操作後、8時間のDB無操作で
MySQLによってセッションを切られていて、再接続が発生した、というだけのことだと思います
> その後、調査を進めてインフラ側にてPINGを定期的に流すシェルを作成し
> 経過を見たところ、値が取れない該当時間帯の数十秒間でレスポンスが極端に悪くなっておりました。
これらからも、同時間帯にNWの混雑・輻輳などによって通信に影響がでるタイミングがあったようですね
kaeru - 投稿数: 264
>fripper様
重ねてフォローありがとうございます。
>エージェントからの値取得でネットワーク接続などに失敗した場合、同エージェントに存在する別のアイテムでも同じ失敗が起こる可能性が
>高いため、同ホストに設定されているエージェント系アイテムが、一括して一定時間だけ取得保留される仕様になっています
ありがとうございます。
"UnreachableDelay=15"設定は、ここにも掛かってくるんですね。
理解しました。
>それらのうちいずれかが、DB接続・DB操作後、8時間のDB無操作で
>MySQLによってセッションを切られていて、再接続が発生した、というだけのことだと思います
承知しました。
ここはあまり問題ではない箇所ということで気にしないようにします。
>これらからも、同時間帯にNWの混雑・輻輳などによって通信に影響がでるタイミングがあったようですね
YESでした。その後調査を進めましたがインフラ側の問題ではあるが、
提供サービスに関して影響は無いという結論が出ましたので、
特に抜本対策は行わずZabbix側でトリガー条件を緩和して障害として検知しないようにしました。
上記、詳細にご回答いただき誠にありがとうございました。