2ch特化型サーバ・ロケーション構築作戦 Part20

サーバダウン(鯖落ち）情報　part94
http://qb5.2ch.net/test/read.cgi/operate/1140710423/325
の件、、、。

live22x[123] の matd 化に向けて、httping(*1)で応答時間を監視していて、
(*1: http://www.vanheusden.com/httping/ )
10パケットに1パケット程度、数秒のディレイが起きていることに気づきました。

で、banana403でdevice_polling(4)を試そうと決め、
もしリブートでしくってもheartbeatによりbanana404にフェイルオーバーするはずだと、
リブートをかけました。

しかし、いつもとリブートの感じが違いました。
いつもはputtyの窓がちゃんと閉じるのですが、今回は閉じずに
ただ反応だけがなくなりました。

で、banana404へのフェイルオーバーは起きたのですが、
「俺のIPアドレスを別のやつ(banana403)も名乗っているぞ」というエラーが404で出始めました。

(続く)

で、「これはおかしいぞ」と思い、
一度 banana404 のリブートもかけてみようと思い立ちました。
(今思うとこれがまずかったと思われ)

で、banana404 は設定を変えずに、単に reboot コマンドでリブートしました。
しかしなぜか、さきほどの banana403 と同じ状態になりました。
つまり窓が閉じずに、反応だけがなくなる状態になりました。
ここで本能的に「まずい」と思いました。

案の定、両方のサーバともサービスがない状態になり、
www2.2ch.net は止まった状態になりました。
で、現在に至ります。

(続く)

今調べてみると、

banana403 実IPアドレス … ping かかる
banana403 実IPアドレス … ping かかる
サービス用 IP アドレス(www2.2ch.net) … ping かかる

という状態にあるようです。
しかし、どのサービスも応答しない状態になっています。

推測ですが、これはリブートではなく、シャットダウンの途中で止まっている
ように思えます。つまり、何らかの理由でシャットダウンできていない。
いつもは閉じる窓が閉じなかった(つまり向こうからTCPのセッションを切ってこなかった)
ことから、ほぼ間違いないと思います。

しかし、設定を変えたbanana403はともかく、
設定を全く変えていないbanana404でも同じことが起きたのは、
かなり不可解です。

heartbeatが悪さをしたのか、
あるいは、remote KVMとかが悪さをしたのか、
あるいは他の原因か、、、。

いずれにせよ現在、remote KVMにアクセスできない状態なので、
(さきほどやってみましたがだめでした。これはSeanさんにさきほど問い合わせしました)
コンソールの状況を確認できないです。

以上が現在の状況です。ううむ、、、。

> (さきほどやってみましたがだめでした。これはSeanさんにさきほど問い合わせしました)

Seanさんから返事が来て、無事にKVMにアクセスできました。

やはりbanana403/404とも、シャットダウンの途中でしくっていました。
というか、Rebooted by ... というシステムログが出て、
プロセスは切られているのに、そこから先に進まない状態。

直感ですが、matd がというか、
たぶんヘビーなパケット処理により、カーネルが何らかの形で止まっているっぽいです。

…ちとまじで限界なので、
ここから先はリブートの中の人に403/404の両サーバをリブートいただいた後に、
別途リブート入れて検証してみることにするです。ううむ。

>>166-167 フェイルオーバしつつロードバランスもするって感じなんでしょうか．興味深いですね．

>>168-172 う〜む......matd の挙動も要観察ですかね．パケットのドロップが発生してるのかどうかとか......

Apache2.2.0の機能でプロセスが終わらないとサービスが切れない機能？があるらしいです。

無理矢理切ってエラー発生して結局システム真紀子み止まった。

てな感じかと｡｡｡

> デイトレーダーの人たちはどうやらものすごい勢いで、
> この掲示板に強く依存しているようです。

デイトレーダーの人はモリタポ買ってね！
と言っても良さそうな気がして来た。

無事(device_pollingしたほうも)上がりました。

>>173
ちと、じっくり調べてみるです。

>>174
今回のサーバではApache 2.0系で、CGI動かしてないです。

WARNING: / was not properly dismounted

両サーバとも、やはり正しく落ちなかった模様。

354 名前：root▲ ★[sage] 投稿日：2006/03/03(金) 11:43:48 ID:???0 ?#
ふうむ、device polling ありだと、うまくないのね。
なし(前の状態)にしたら、つながりました。


まだよくわかりませんが、
device polling はいまやなしのほうが、よさげなのかも。

で、いろいろ変えてみる前に、
まずは今の設定での効率を調べて、状況をきちんと把握する

ことから始めようと。

ということで、httping -c 100 -g http://www2.2ch.net/ の結果(cvsup.peko.2ch.netから)

connected to www2.2ch.net:80, seq=73 time=18.44 ms
connected to www2.2ch.net:80, seq=74 time=3014.49 ms
(略)
connected to www2.2ch.net:80, seq=75 time=21.35 ms
timeout receiving reply from host
connected to www2.2ch.net:80, seq=77 time=16.91 ms
connected to www2.2ch.net:80, seq=78 time=14.07 ms
(略)
connected to www2.2ch.net:80, seq=87 time=17.59 ms
connected to www2.2ch.net:80, seq=88 time=11.90 ms
connected to www2.2ch.net:80, seq=89 time=3017.84 ms
connected to www2.2ch.net:80, seq=90 time=3015.85 ms
(略)
connected to www2.2ch.net:80, seq=96 time=471.73 ms
connected to www2.2ch.net:80, seq=97 time=6219.80 ms
connected to www2.2ch.net:80, seq=98 time=15.69 ms
connected to www2.2ch.net:80, seq=99 time=19.33 ms
--- http://www2.2ch.net/ ping statistics ---
100 connects, 99 ok, 1.00% failed
round-trip min/avg/max = 11.7/449.1/6219.8 ms

同じく、www.2ch.net

connected to www.2ch.net:80, seq=94 time=2.66 ms
connected to www.2ch.net:80, seq=95 time=2.71 ms
connected to www.2ch.net:80, seq=96 time=2.67 ms
connected to www.2ch.net:80, seq=97 time=2.72 ms
connected to www.2ch.net:80, seq=98 time=2.69 ms
connected to www.2ch.net:80, seq=99 time=2.84 ms
...
--- http://www.2ch.net/ ping statistics ---
100 connects, 100 ok, 0.00% failed
round-trip min/avg/max = 2.6/2.8/4.6 ms

同じく、live22x.2ch.net

connected to live22x.2ch.net:80, seq=95 time=3.17 ms
connected to live22x.2ch.net:80, seq=96 time=3.26 ms
connected to live22x.2ch.net:80, seq=97 time=3.54 ms
connected to live22x.2ch.net:80, seq=98 time=3.13 ms
connected to live22x.2ch.net:80, seq=99 time=2.97 ms
--- http://live22x.2ch.net/ ping statistics ---
100 connects, 100 ok, 0.00% failed
round-trip min/avg/max = 3.0/3.2/6.3 ms

で、感想ですが、

matd はユーザランドで動いているせいか、15ms〜18ms 程度
遅延が生じるようです。(これは想定内)

しかし、たまにがくっと遅くなることがあります。(想定外です)
>>179 では100カウントやって、1つタイムアウトになりました。
これの原因が知りたいところです。

banana403 や banana404 からやってみればいいのかな。

このへんで、まずはめしを。

>>182
>matd はユーザランドで動いているせいか、15ms〜18ms 程度
>遅延が生じるようです。(これは想定内)

ユーザランドということもあるかも知れませんが，
http://qb5.2ch.net/test/read.cgi/operate/1121886018/901
　　>アプリとして動くみたいなので、カーネルとの切り替えがばかにならないのかなと。
　　>(パケット1個単位で切り替えですよね。)

　　FreeBSD では BPF，Solaris では bufmod によるバッファリングが効いて
　　パケット取り込みはある程度まとめて行われると思いますが，
　　パケットの取りこぼしとか発生しないかどうかってのは，正直わかりません......

のようにバッファリングしてるわけですが，その際の待ち時間が最大 10ms に
なっているので，それもあるかも知れません．

>しかし、たまにがくっと遅くなることがあります。(想定外です)
> >>179 では100カウントやって、1つタイムアウトになりました。
>これの原因が知りたいところです。

何らかの原因でパケットの取りこぼしが発生していることも考えられますが，
そうだとするとなぜ取りこぼすのか（処理が追い付かないのか，それとも別の要因か）ってのが問題ですね．

>>183
> のようにバッファリングしてるわけですが，その際の待ち時間が最大 10ms に
> なっているので，それもあるかも知れません．

なるほど、なるほど。

> 何らかの原因でパケットの取りこぼしが発生していることも考えられますが，
> そうだとするとなぜ取りこぼすのか（処理が追い付かないのか，それとも別の要因か）
> ってのが問題ですね．

そうですね。まさにこれを調べたいということで。

そもそも、普通のpingがいまいちであるらしいことに気がついた。

...
64 bytes from 206.223.150.74: icmp_seq=4 ttl=64 time=0.175 ms
64 bytes from 206.223.150.74: icmp_seq=5 ttl=64 time=0.264 ms
64 bytes from 206.223.150.74: icmp_seq=6 ttl=64 time=0.242 ms
64 bytes from 206.223.150.74: icmp_seq=7 ttl=64 time=0.205 ms
64 bytes from 206.223.150.74: icmp_seq=9 ttl=64 time=0.273 ms
64 bytes from 206.223.150.74: icmp_seq=10 ttl=64 time=0.234 ms
64 bytes from 206.223.150.74: icmp_seq=11 ttl=64 time=0.214 ms
64 bytes from 206.223.150.74: icmp_seq=12 ttl=64 time=0.195 ms
64 bytes from 206.223.150.74: icmp_seq=13 ttl=64 time=0.155 ms
64 bytes from 206.223.150.74: icmp_seq=14 ttl=64 time=0.259 ms
...
--- live22y.2ch.net ping statistics ---
30 packets transmitted, 28 packets received, 6% packet loss
round-trip min/avg/max/stddev = 0.155/0.222/0.287/0.036 ms

tcpdump とかで，httping かけてる時の banana403 / banana404 上でのパケットの流れ見てみるとか
......と言おうと思ったら

>>185 う〜む，これはネットワークとかの問題でしょうか？

>>186
XOの高性能スイッチに繋がっているサーバの間の通信について、
パケットがきちんと通っているか、精査してみます。

おさらい: XOの２ちゃんねるラックにあって、高性能スイッチに繋がっているサーバ

サーバ名 ホスト名 接続I/F一覧
○雪だるま系 206.223.150.0/24 192.168.100.0/24
tiger503 live22x4 em0/em1
tiger507 live22x5 em0/em1
tiger2522 live22 em0/em1
tiger2523 live22x1 em0/em1
tiger2524 live22x2 em0/em1
tiger2525 live22x3 em0/em1
banana403 live22b1/www2 fxp0 fxp1
banana404 live22b2/www2 fxp0 fxp1

○携帯系 206.223.150.0/24 192.168.0.0/24
tiger511 blackgoat3 em0/em1
tiger512 blackgoat4 em0/em1
tiger2507 c-au4 em0/em1
tiger2508 c-au5 em0/em1
tiger2509 c-au6 em0/em1
tiger2510 c-docomo5 em0/em1
tiger2511 c-docomo6 em0/em1
tiger2512 c-docomo7 em0/em1
banana405 c-others1/c1 fxp0 fxp1
banana406 c-others2/c2 fxp0 fxp1

○どちらでもない系
tiger504 game10 em0
tiger509 news19 em0
tiger510 hobby7 em1
cobra2245 bbq bge0
(banana402 stock fxp0) 移動済みのはずだが、こないだの全停電でなぜか通信が途絶えた

まずは雪だるま系のパブリック側。
ping -c 30 サーバ名 を実行

tiger2522 から、
tiger2523 ○
tiger2524 ○
tiger2525 ○
tiger503 ×
--- tiger503.maido3.com ping statistics ---
30 packets transmitted, 26 packets received, 13% packet loss
round-trip min/avg/max/stddev = 0.123/0.206/0.274/0.051 ms
tiger507 ○
banana403 ×
--- banana403.maido3.com ping statistics ---
30 packets transmitted, 27 packets received, 10% packet loss
round-trip min/avg/max/stddev = 0.135/0.192/0.298/0.031 ms
banana404 ×
--- banana404.maido3.com ping statistics ---
30 packets transmitted, 24 packets received, 20% packet loss
round-trip min/avg/max/stddev = 0.135/0.229/0.309/0.044 ms

>>188 修正

サーバ名 ホスト名 接続I/F一覧
○雪だるま系 206.223.150.0/24 192.168.100.0/24
tiger503 live22x4 em0/em1
tiger507 live22x5 em0/em1
tiger2522 live22 em0/em1
tiger2523 live22x1 em0/em1
tiger2524 live22x2 em0/em1
tiger2525 live22x3 em0/em1
cobra2247 未割り当て bge0/bge1
banana403 live22b1/www2 fxp0 fxp1
banana404 live22b2/www2 fxp0 fxp1

○携帯系 206.223.150.0/24 192.168.0.0/24
tiger511 blackgoat3 em0/em1
tiger512 blackgoat4 em0/em1
tiger2507 c-au4 em0/em1
tiger2508 c-au5 em0/em1
tiger2509 c-au6 em0/em1
tiger2510 c-docomo5 em0/em1
tiger2511 c-docomo6 em0/em1
tiger2512 c-docomo7 em0/em1
banana405 c-others1/c1 fxp0 fxp1
banana406 c-others2/c2 fxp0 fxp1

○どちらでもない系
tiger504 game10 em0
tiger509 news19 em0
tiger510 hobby7 em1
cobra2245 bbq bge0
(banana402 stock fxp0) 移動済みのはずだが、こないだの全停電でなぜか通信が途絶えた

>>189 に追加。

cobra2247 ○

banana403 から、
banana404 ○
tiger503 ○
tiger507 ×
--- tiger507.maido3.com ping statistics ---
30 packets transmitted, 24 packets received, 20% packet loss
round-trip min/avg/max/stddev = 0.135/0.214/0.270/0.038 ms
tiger2522 ×
--- tiger2522.maido3.com ping statistics ---
30 packets transmitted, 28 packets received, 6% packet loss
round-trip min/avg/max/stddev = 0.135/0.197/0.259/0.037 ms
tiger2523 ×
--- tiger2523.maido3.com ping statistics ---
30 packets transmitted, 27 packets received, 10% packet loss
round-trip min/avg/max/stddev = 0.148/0.207/0.316/0.042 ms
tiger2524 ×
--- tiger2524.maido3.com ping statistics ---
30 packets transmitted, 26 packets received, 13% packet loss
round-trip min/avg/max/stddev = 0.136/0.206/0.375/0.048 ms
tiger2525 ×
--- tiger2525.maido3.com ping statistics ---
30 packets transmitted, 26 packets received, 13% packet loss
round-trip min/avg/max/stddev = 0.132/0.204/0.386/0.053 ms
cobra2247 ×
--- cobra2247.maido3.com ping statistics ---
30 packets transmitted, 27 packets received, 10% packet loss
round-trip min/avg/max/stddev = 0.117/0.208/0.423/0.063 ms

これは、、、。

2つの「うまく通信できるグループ」があって、
その間のパケットはぼろぼろロストしてるってことなのか?

グループA tiger507 tiger2522 tiger2523 tiger2524 tiger2525 cobra2247
グループB tiger503 banana403 banana404

>>187-193 乙です．となると......スイッチがおかしいとか？

原因切り分けのため、
まったく関係ないところ(XOの外: PIE内部)からやってみた。

banana273 [206.223.147.225] から、

tiger2522 ○
tiger503 ×
--- tiger503.maido3.com ping statistics ---
30 packets transmitted, 25 packets received, 16% packet loss
round-trip min/avg/max/stddev = 1.280/1.428/1.766/0.116 ms
banana403 ×
--- banana403.maido3.com ping statistics ---
30 packets transmitted, 28 packets received, 6% packet loss
round-trip min/avg/max/stddev = 0.658/0.899/2.144/0.365 ms
banana404 ×
--- banana404.maido3.com ping statistics ---
30 packets transmitted, 28 packets received, 6% packet loss
round-trip min/avg/max/stddev = 0.675/0.764/1.148/0.091 ms

tiger503, banana403, banana404 だけがおかしい、で正解ですね。
でも、相互の通信はうまくいくと。

スイッチの設定上の問題の予感がします。
もう少し調べてから、状況(問題発生)をSeanさんにエスカレーションする方向で。

で、ここまでやっておじさんが
「stock (= banana402) と be (= ブラジル)との間の通信が微妙」と言っていたのを
思い出しました。

banana402は移動したと言っていますが、この間の電源トラブルのときに
巻き添えで落ちたので、同じスイッチに(あいかわらず)繋がっているのかもしれません。
これもあわせて、調べてみます。

> banana402は移動したと言っていますが、この間の電源トラブルのときに
> 巻き添えで落ちたので、同じスイッチに(あいかわらず)繋がっているのかもしれません。
> これもあわせて、調べてみます。

わーい、だめだこりゃ。

--- banana402.maido3.com ping statistics ---
30 packets transmitted, 23 packets received, 23% packet loss
round-trip min/avg/max/stddev = 0.665/0.734/0.801/0.041 ms

ちょっとひどそうなので、
>>190 のやつ全部、調べなおす方向で。

で、XOだけならいいんだけどということで、age。

なるほど、今までの不思議に思っていたことが
何か見えてくるかもしれませんね。

matd の挙動調査から思わぬ展開に......
でもまぁこういう問題を発見できたのはよかったと．

>>199
そうですね。
こういうのは、何かきっかけが無いと分かりにくいですから。
問題が発見できたのは良かったと思います。

banana273 から、

banana405 ×
--- banana405.maido3.com ping statistics ---
30 packets transmitted, 24 packets received, 20% packet loss
round-trip min/avg/max/stddev = 0.657/7.266/158.052/31.441 ms
banana406 ○

不思議だ。同じOSバージョン同じサブネット同じネットワークI/Fなのに。
やはり、スイッチですね。

まさか「proxyに繋がらない。。。」の頻発も、これが原因?

ってことは、プライベート側もきちんと精査しないといかんということですね。

banana273 (XOの外にあるone of standard banana)から、まとめ。

パブリック側I/Fでパケット落ちが起きているのは、
banana402 = stock
banana403 = www2
banana404 = www2
banana405 = c/c1/c-others1
tiger503 = live22x4
tiger2511 = c-docomo6
の6台。

banana402 ×
banana403 ×
banana404 ×
banana405 ×
banana406 ○

tiger503 ×
tiger504 ○
tiger509 ○
tiger510 ○
tiger511 ○
tiger512 ○

tiger2507 ○
tiger2508 ○
tiger2509 ○
tiger2510 ○
tiger2511 ×
--- tiger2511.maido3.com ping statistics ---
30 packets transmitted, 26 packets received, 13% packet loss
round-trip min/avg/max/stddev = 0.645/0.752/0.871/0.049 ms
tiger2512 ○

tiger2522 ○
tiger2523 ○
tiger2524 ○
tiger2525 ○

cobra2245 ○
cobra2247 ○

続いて、プライベート側の調査。
プライベート側は目的毎に独立した2つのサブネットあり。

雪だるま系: 192.168.100.0/24
banana403 から。

tiger507のプライベート側がだめ。

banana404 ○
tiger503 ○
tiger507 ×
--- 192.168.100.6 ping statistics ---
30 packets transmitted, 24 packets received, 20% packet loss
round-trip min/avg/max/stddev = 0.147/0.262/1.422/0.245 ms
tiger2522 ○
tiger2523 ○
tiger2524 ○
tiger2525 ○
cobra2247 ○

(続き)

携帯系: 192.168.0.0/24
banana405 から。

プライベート側I/Fでパケット落ちが起きているのは、
banana406 = c/c2/c-others2
tiger2509 = c-au6
tiger2510 = c-docomo5
tiger2512 = c-docomo7
の4台。

ごていねいに、全キャリアに一つ以上異常なのがある。
この「ババ｣を引くと、「proxyに繋がらない。。。」が頻発していると。

banana406 ×
--- 192.168.0.1 ping statistics ---
30 packets transmitted, 26 packets received, 13% packet loss
round-trip min/avg/max/stddev = 0.150/0.263/1.020/0.196 ms
tiger511 ○
tiger512 ○
tiger2507 ○
tiger2508 ○
tiger2509 ×
--- 192.168.0.163 ping statistics ---
30 packets transmitted, 27 packets received, 10% packet loss
round-trip min/avg/max/stddev = 0.140/0.307/1.027/0.204 ms
tiger2510 ×
--- 192.168.0.164 ping statistics ---
30 packets transmitted, 27 packets received, 10% packet loss
round-trip min/avg/max/stddev = 0.141/0.222/0.352/0.059 ms
tiger2511 ○
tiger2512 ×
--- 192.168.0.166 ping statistics ---
30 packets transmitted, 28 packets received, 6% packet loss
round-trip min/avg/max/stddev = 0.153/0.290/1.097/0.225 ms

ということで、

1) なぜこんなことがXOの特定のスイッチで起こったのか

状況をみる限りでは、
何らかの意図(帯域制限など)を持って設定しているとは考えられないおかしさです。

=> 先日の停電でスイッチがおかしくなった or 壊れた?
=> 何か設定を変えた?
=> その他?

2) どうすれば直るのか

=> スイッチのリセット?
=> スイッチの設定修正?
=> スイッチの交換?

なお、このスイッチは1Gbps対応・VLAN設定対応等可能で、
処理能力もスイッチとしてはPIEでいちばんでかいもののはずです。

つまりもし万一スイッチのハードウェア障害だとすると
tiger サーバや cobra サーバと同様、
交換部品がどきどき、、、以下略 の予感も。

いずれにせよXOの一部サーバの通信に異常が発生している、
という状況はつかみました。

また携帯系の「proxyに繋がらない。。。」が急に多発するようになったのも、
ほぼこれが原因と考えられます。

状況を書いて、Seanさんに調査と修正依頼を出すことにします。

とりあえず、以上で、
しばらく本業のため、依頼メール出すのはしばらく後になります。