blog

[翻訳] これは厳密にはTCPの仕様違反である。

この記事の翻訳元記事では、サーバー側のソッカーリークがCLOSE-WAIT状態のままであるにもかかわらず、クライアント側のFIN-WAIT2状態がタイムアウトしてそのソケットを再取得し、新たに接続を確...

Oct 3, 2020 · 9 min. read
シェア

元の記事を読む

この記事は記事を翻訳したもので、サーバー側のソッカー漏れがCLOSE-WAIT状態のまま、クライアントのFIN-WAIT2状態のタイムアウトを再利用し、新たに接続を確立するためにソケットを使用することで、Connection TIme Out状態になることを説明しています。この現象とバックログオーバーフロー現象は少し似ているので、このブログではこの記事の翻訳を転載し、読者の皆さんと一緒に進めていきます。

""これ""は厳密にはTCPの仕様違反です

「FIN_WAIT_2を自動的にクローズする""This""は厳密にはTCPの仕様違反です。

ネットワーク上の別の奇妙な問題のデバッグを依頼されました。どうやらCloudFlare経由の接続が522 HTTPエラーでタイムアウトすることがあるようです。

CloudFlareの522エラーは、エッジサーバーとオリジンサーバー間の接続問題を示しています。最も一般的な原因はソースサーバー側にあります。ソースサーバーが遅い、オフライン、またはパケットロスが多い場合です。こちら側で問題が発生することはほとんどありません。

私がデバッグしたケースでは、そのどちらでもありませんでした。CloudFlareとオリジンサーバー間のインターネット接続は完璧でした。CloudFlareとオリジンサーバー間のインターネット接続は完璧でした。ではなぜ522エラーが表示されるのでしょうか?

この問題の根本原因は非常に複雑です。デバッグを重ねた結果、重要な現象が発見されました。何千回もの実行で、テストプログラムが同じコンピュータ上の2つのデーモン間の接続を確立できないことがあったのです。正確には、NGINXインスタンスがローカルホスト上の内部アクセラレーションサービスとのTCP接続を確立しようとしてタイムアウトエラーが発生しました。

何を探すべきかがわかれば、昔ながらのnetcatでこれを再現できます:

$ nc .1 5000 -v
nc: connect to .1 port 5000 (tcp) failed: Connection timed out

straceを表示します:

socket(PF_INET, SOCK_STREAM, IPPROTO_TCP) = 3
connect(3, {sa_family=AF_INET, sin_port=htons(5000), sin_addr=inet_addr(".1")}, 16) = -110 ETIMEDOUT

netcatはローカルホストへの接続を確立するためにconnect()を呼び出します。tcpdumpは、connect()がループバックを経由してSYNパケットを送信していることを確認していますが、SYN + ACKを受信していません:

$ sudo tcpdump -ni lo port 5000 -ttttt -S
. IP . > .1.5000: Flags [S], seq , win 43690, options [mss 65495,sackOK,TS val ecr 0,nop,wscale 7], length 0
. IP . > .1.5000: Flags [S], seq , win 43690, options [mss 65495,sackOK,TS val ecr 0,nop,wscale 7], length 0
... 5 more ...

少し待ってください。何が起こったのでしょうか?

SYNパケットはループバックのlocalhost経由でクローズされましたが、応答はありませんでした。

ループバックの輻輳

まず頭に浮かぶのは、インターネットの安定性です。SYNパケットが失われたのでは?あまり知られていないことですが、ループバックインターフェースではパケットロスや輻輳は起こりえません。アプリケーションがループバックインターフェースにパケットを送信すると、すぐに内部の送信システムコールによって処理され、適切な宛先に配送されます。センドバックバッファはありません。send backの呼び出しは、ネットワークスタックの配送メカニズムであるiptablesをトリガーして、ターゲットアプリケーションの適切なキューにパケットを配送します。ターゲットアプリケーションがそのバッファにいくらかのスペースを持っていると仮定すると、ループバックを経由してパケットが失われることはありません。

もしかしたら、アプリケーションの例外をリッスンしているのかもしれません。

通常、localhost への接続がタイムアウトすることはありません。極端な例ですが、リスニングしているアプリケーションのaccept()の呼び出しが十分に速くない場合に、このようなことが起こる可能性があります。

このような場合、デフォルトの動作は新しい SYN パケットを廃棄することです。リスニングしているソケットの accept キューが一杯の場合、新しい SYN パケットはドロップされます。その目的は、バックオフを起こして着信コネクションの速度を落とすことです。ピアは最終的にSYNパケットを再送すべきであり、うまくいけば、それまでにアクセプトキューは解放されるでしょう。tcp_abort_on_overflow この動作は、.

訳者注: これは基本的に、コネクションタイムアウトアプリケーションの非常に一般的な問題で、コネクションキューがいっぱいになるとキューがオーバーフローしてSYNがドロップされ、SYNを再送信しても応答がないためにクライアントがコネクションタイムアウトエラーを報告するというものです:

しかし、この受信キューのオーバーフローはリスニングしているアプリケーションの受信キューは空でした。これは以下の ss コマンドで確認しました:

$ ss -n4lt 'sport = :5000'
State Recv-Q Send-Q Local Address:Port Peer Address:Port
LISTEN 0 128 *:5000 *:*

この Send-Q 列は表示listen()syscall に与えられた バックログ/受諾キューのサイズを示して います。

質問

復習:localhostへの接続は確立されています。ループバックを経由してsynパケットが送信されます。ループバックなので、それらはリスニングしているソケットに渡されます。リスニングしているソケットはキューを空として受け取りますが、SYN + ACKを見ません。

さらに調査を進めると、いくつかの奇妙な点が明らかになりました。何百ものCLOSE_WAITソケットがありました:

$ ss -n4t | head
State Recv-Q Send-Q Local Address:Port Peer Address:Port
CLOSE-WAIT 1 0 .1:.0.1:36599
CLOSE-WAIT 1 0 .1:.0.1:36467
CLOSE-WAIT 1 0 .1:.0.1:36154
CLOSE-WAIT 1 0 .1:.0.1:36412
CLOSE-WAIT 1 0 .1:.0.1:36536
...

CLOSE_WAITとは何ですか?

それは理にかなっています。確かに、リスンしているアプリケーションがソケットをリークしていないことを確認することは可能です。

しかし、ソケットのリークはすべてを説明するものではありません。

通常、Linuxプロセスは最大1,024個のファイル記述子を開くことができます。アプリケーションがファイル記述子を使い果たした場合、acceptsyscallはEMFILEエラーを返します。アプリケーションがこのエラー状態をさらに処理すると、受信するSYNパケットが失われる可能性があります。acceptコールに失敗しても、ソケットがacceptキューから脱落してacceptキューが大きくなることはありません。アクセプトキューが枯渇することはなく、最終的にはオーバーフローします。受信キューのオーバーフローは、SYNパケットの損失や接続の失敗を引き起こす可能性があります。

しかし、ここで起こっているのはそのようなことではありません。アプリケーションはファイル記述子を使い果たしていないのです。/proc/<pid>/fdこれは、ディレクトリ:

$ ls /proc/` pidof listener `/fd | wc -l
517

517個のファイルディスクリプタは、ファイルディスクリプタの上限である1,024個をはるかに下回っています。また、acceptキューが空であることもわかります。では、なぜ接続がタイムアウトするのでしょうか?

何が起こっているのでしょうか?

問題の根本的な原因は、アプリケーションがソケットをリークしていることです。

しかし、接続がタイムアウトした後も、この現象は原因不明のままです。

何が起こったのか?

リッスン中のアプリケーションは、常にCLOSE_WAIT TCP状態にあるソケットをリークします。これらのソケットは次のようになります。接続の相手側のクライアント・ソケットは、適切にクローズされ、クリーンアップされています。

クライアント・アプリケーションが終了すると、ソケットはFIN_WAIT_1状態になり、すぐにFIN_WAIT_2状態に遷移します。クライアントがFINパケットを受信すると、FIN_WAIT_2状態はTIME_WAITに遷移するはずです。// This is a trivial TCP server leaking sockets. // listener.go package main import ( "fmt" "net" "time" ) func handle(conn net.Conn) { defer conn.Close() for { time.Sleep(time.Second) } } func main() { IP := "" Port := 5000 listener, err := net.Listen("tcp4", fmt.Sprintf("%s:%d", IP, Port)) if err != nil { panic(err) } i := 0 for { if conn, err := listener.Accept(); err == nil { i += 1 if i < 800 { go handle(conn) } else { conn.Close() } } else { panic(err) } } } Linuxではこれは60秒で、sysctlによって制御されます。

問題はここから始まります。ソケットはまだ CLOSE_WAIT 状態で、再利用のためにクリーンアップされ準備されています。これが起こると、結果はめちゃくちゃになります:

ソケットの一方はSYN_SENT状態から進むことができず、もう一方はCLOSE_WAIT状態にあります。

再現方法

これはすべて、ソケットをリークしてclose()を呼び忘れるリスニングアプリケーションから始まりました。このエラーは複雑なアプリケーションで発生します。あるエラーのアプリケーションコードを以下に示します。

// This is a trivial TCP server leaking sockets.
// listener.go
package main
import (
	"fmt"
	"net"
	"time"
)
func handle(conn net.Conn) {
	defer conn.Close()
	for {
		time.Sleep(time.Second)
	}
}
func main() {
	IP := ""
	Port := 5000
	listener, err := net.Listen("tcp4", fmt.Sprintf("%s:%d", IP, Port))
	if err != nil {
		panic(err)
	}
	i := 0
	for {
		if conn, err := listener.Accept(); err == nil {
			i += 1
			if i < 800 {
				go handle(conn)
			} else {
				conn.Close()
			}
		} else {
			panic(err)
		}
	}
}

実行すると、最初は何も起こりません:

$ go build listener.go && ./listener &
$ ss -n4tpl 'sport = :5000'
State Recv-Q Send-Q Local Address:Port Peer Address:Port
LISTEN 0 65535 *:5000 *:* users:(("listener",pid=28443,fd=3))

次にクライアント・アプリケーションがあります。クライアントは正しく動作し、接続を確立し、一定時間後に接続を閉じます。ncを使うことができます:

$ nc -4 localhost 5000 &
$ ss -n4tp '( dport = :5000 or sport = :5000 )'
State Recv-Q Send-Q Local Address:Port Peer Address:Port
ESTAB 0 0 .1:.0.1:25136 users:(("listener",pid=28443,fd=4))
ESTAB 0 0 .1:.0.0.1:5000 users:(("nc",pid=28880,fd=3))

次のステップは、クライアント接続を普通に閉じることです:

kill `pidof nc`
$ kill `pidof nc`

しばらくすると、FIN_WAIT_2は期限切れになります:

State Recv-Q Send-Q Local Address:Port Peer Address:Port
CLOSE-WAIT 1 0 .1:.0.1:25136 users:(("listener",pid=28443,fd=4))
FIN-WAIT-2 0 0 .1:.0.0.1:5000

しかしCLOSE_WAITソケットはまだ存在します!リスナープログラムのファイル記述子リークのため、カーネルはFIN_WAIT状態に移行することができません。ソケットは無期限にCLOSE_WAIT状態のままです。このレガシーCLOSE_WAITは、同じポートのペアが再使用されなければ問題にはなりません。しかし、残念ながら、このようなことが起こり、問題を引き起こします。

しかし、CLOSE_WAIT ソケットは残ります!リスナープログラムのファイル記述子リークのため、カーネルはこのソケットをFIN_WAIT状態にすることができません。ソケットは無期限にCLOSE_WAIT状態になります。同じポートのペアが再使用されることがなければ、このCLOSE_WAITのワンダリングは問題になりません。しかし、残念なことに、CLOSE_WAIT は発生し、問題を引き起こします。

これを確認するには、数百のncインスタンスを起動し、カーネルが競合するポート番号をそのうちの1つに割り当てることを期待します。影響を受けたncはしばらくの間connect()されたままになります:

State Recv-Q Send-Q Local Address:Port Peer Address:Port
CLOSE-WAIT 1 0 .1:.0.1:25314 users:(("listener",pid=28443,fd=6)) timer:(keepalive,2.076ms,0)

ssを使用して、ポートが本当に競合していることを確認できます:

$ nc -v -4 localhost 5000 -w0
...

この例では、カーネルはソース・アドレスをncプロセスに割り当てます。このTCPストリームは、コネクション・リスナー・アプリケーションに接続するために使用できます。ただし、リスナーは以前に接続したストリームをまだ使用しており、CLOSE_WAIT状態を維持しているため、ストリームを逆割り当てすることはできません。

カーネルは混乱します。カーネルはSYNパケットを再試行しますが、もう一方のTCPソケットがCLOSE_WAIT状態であるため、応答することはありません。最終的に、影響を受けたnetcatは、不運なETIMEDOUTエラーメッセージによって死んでしまいます:

SYN-SENT 0 1 .1:.0.0.1:5000 users:(("nc",))
CLOSE-WAIT 1 0 .1:.0.1:36613 users:(("listener",))

あまり知られていないことですが、手動でソースIPを選択しない限り、カーネルが自動的に割り当てるソースポートはインクリメンタルです。この場合、ソース・ポートはランダムです。このbashスクリプトは、一時的なポート範囲にランダムに分散したCLOSE_WAITソケットの地雷原を作成します。

翻訳終了。

トランスレータのテスト現象

キャッチパケットの再現は、ポートが再利用されるときに見ることができる、サーバー側のclose_waitが存在し、唯一のACKメッセージのリターンは、クライアントが受信し、RSTを送信してから、クライアント1sのタイムアウトにつながる可能性があり、再試行、本文では再現されない、"close_waitが常に存在し、SYNメッセージを無視する"。結論

...
nc: connect to localhost port 5000 (tcp) failed: Connection timed out

何はともあれ、cloudfareのケースはclose_waitの問題に焦点を当てることを目的としており、サーバ側が閉じたコネクションを適切に処理しない場合、様々なタイムアウトの問題につながる可能性があります。

この記事の現象は、中間にファイアウォールがあって関連性のないACKをブロックしているために、クライアントがコネクションをリセットするためのRSTを送らないということでしょうか。

読者の皆さんは、ご自身でテストすることができます。

Read next

[PubGrub: 次世代バージョン管理ソリューション

今日、突然ですが: 単位伝播、論理スキーム、競合駆動学習などのように聞こえる用語を使用した、他のバージョンの解法よりも高速に実行され、バグの少ない新しいバージョンの解法アルゴリズムが、pubパッケージマネージャに統合されました。pub パッケージマネージャと Dart 2.0.0-dev に統合されました。

Oct 3, 2020 · 8 min read