Zenn
Open13

オーバレイネットワークを構築するGo言語ライブラリとそれを用いた分散KVSの開発

#
KVS
#
overlay
#
distributed
#
dht
#
gossip
ryo_gridryo_grid

作ったライブラリで構築したオーバレイNWでのコネクション確立が激遅なのでコネクションの使いまわしで対処したい

  • 元々KVSはgRPCが使われていたが、トランスポートを自作ライブラリで置き換えることができなかったので、REST（HTTP/1.x）にした上で、オーバレイNW上で動作させるようにした
    • なお、GordというChord（DHT）のOSS実装があり、それをforkして、機能追加する形でKVSを実装した
  • データアクセスがなくとも、DHTではノード間で頻繁に通信を行うので、コネクションプールしないと辛い。今回のオーバレイNWだとコネクション確立が激遅なのでなおさら
  • HTTP/1.x でもそれなりにコネクションは使いまわしてくれるはずだが、なんだかうまくいってなさそうに見えるので、そこらへんをもっとよしなにやってくれそうなHTTP/2で動かそうとしている

https://github.com/ryogrid/gord-overlay/tree/debugging-after-cpu-usage-decreased
https://github.com/ryogrid/gord-overlay/tree/debugging-after-cpu-usage-decreased

ryo_gridryo_grid

HTTP/2化がうまくいかない （１）

  • 分散KVSは元々gRPCでノード間通信をしていたが、先述からREST（HTTP/1.x）で通信をするように修正を入れてから、オーバレイNW上で動作させるようにした
  • RESTへの移行は gRPC のスキーマ定義から、RESTなどでの通信も可能な形のコード生成を行う connect-go というフレームワーク・ツールを用いた
  • 今は、先述より、HTTP/1.x での通信を HTTP/2で行わせようとしている
  • connect-goはTLS無しでのHTTP2通信に対応していて、その方法は公式のドキュメントにある
  • この方法で、ドキュメントの通り素直にTCPを使った場合動いた
  • 一方で、オーバレイNW上で通信するように、トランスポート回りの実装を置き換えるとHTTP2のシーケンスが途中でエラーになってしまう
    • 参考: "TCPの時"と"置き換えした時"の差分
    • http/2のデバッグ情報は GODEBUG="http2debug=2" と環境変数を設定しておくと出力される。その他の出力は自前で出しているもの
    • 本来、多数のノードで動作させる想定のプログラムだが、現在の問題の調査は2ノードでの動作を見れば十分なので、そこでの出力やら見解を下には書いている
サーバ側
PS C:\Data\work\gord-overlay> .\gordolctl.exe -l 127.0.0.1:20000
peerHost:  0.0.0.0:20000
NewOverlayPeer: peers= []
OverlayListener::Accept called 30400
gossip> 2024/01/20 19:06:15 mesh router starting (30400)
time="2024-01-20T19:06:15+09:00" level=info msg="Running Gord server..."
time="2024-01-20T19:06:15+09:00" level=info msg="Gord is listening on 127.0.0.1:20000:20001"
time="2024-01-20T19:06:15+09:00" level=info msg="Running Chord server..."
time="2024-01-20T19:06:15+09:00" level=info msg="Chord listening on 127.0.0.1:20000:20000"
time="2024-01-20T19:06:15+09:00" level=info msg="Chord listening on 30400"
GossipMessageManager.onPacketReceived called. src: 00:00:00:00:9f:ab  streamId: 10267  bufSize: 17
GossipMessageManager.SendToRemote called. dest: 00:00:00:00:9f:ab streamID: 10267
&{40875 0.0.0.0:20002 10267}
GossipMessageManager.SendToRemote called. dest: 00:00:00:00:9f:ab streamID: 10267
GossipMessageManager.onPacketReceived called. src: 00:00:00:00:9f:ab  streamId: 10267  bufSize: 40
GossipMessageManager.SendToRemote called. dest: 00:00:00:00:9f:ab streamID: 10267
GossipMessageManager.onPacketReceived called. src: 00:00:00:00:9f:ab  streamId: 10267  bufSize: 76
GossipMessageManager.SendToRemote called. dest: 00:00:00:00:9f:ab streamID: 10267
GossipMessageManager.onPacketReceived called. src: 00:00:00:00:9f:ab  streamId: 10267  bufSize: 48
GossipMessageManager.SendToRemote called. dest: 00:00:00:00:9f:ab streamID: 10267
OverlayListener::Accept fin <nil>
GossipMessageManager.SendToRemote called. dest: 00:00:00:00:9f:ab streamID: 10267
GossipMessageManager.onPacketReceived called. src: 00:00:00:00:9f:ab  streamId: 10267  bufSize: 16
OverlayListener::Accept called 30400
GossipSession.RemoteAddr called: 40875
0.0.0.0:20002
OverlayStream::RemoteAddr called  0.0.0.0:20002
GossipSession.RemoteAddr called: 40875
0.0.0.0:20002
GossipMessageManager.onPacketReceived called. src: 00:00:00:00:9f:ab  streamId: 10267  bufSize: 40
GossipMessageManager.onPacketReceived called. src: 00:00:00:00:9f:ab  streamId: 10267  bufSize: 92
GossipMessageManager.onPacketReceived called. src: 00:00:00:00:9f:ab  streamId: 10267  bufSize: 172
GossipMessageManager.onPacketReceived called. src: 00:00:00:00:9f:ab  streamId: 10267  bufSize: 72
GossipMessageManager.onPacketReceived called. src: 00:00:00:00:9f:ab  streamId: 10267  bufSize: 40
GossipMessageManager.SendToRemote called. dest: 00:00:00:00:9f:ab streamID: 10267
GossipMessageManager.onPacketReceived called. src: 00:00:00:00:9f:ab  streamId: 10267  bufSize: 368
datachannel ERROR: 2024/01/20 19:06:25 Failed to handle DCEP: invalid Message Type &{0 0 0 [] []}
OverlayStream::Read called 64 <nil>
OverlayStream::Read called 0 <nil>
2024/01/20 19:06:25 h2c: attempting h2c with prior knowledge.
GossipSession.RemoteAddr called: 40875
0.0.0.0:20002
OverlayStream::RemoteAddr called  0.0.0.0:20002
GossipSession.RemoteAddr called: 40875
0.0.0.0:20002
GossipSession.RemoteAddr called: 40875
0.0.0.0:20002
OverlayStream::RemoteAddr called  0.0.0.0:20002
GossipSession.RemoteAddr called: 40875
0.0.0.0:20002
2024/01/20 19:06:25 http2: server connection from 0.0.0.0:20002 on 0xc0002b4000
2024/01/20 19:06:25 http2: Framer 0xc0001de1c0: wrote SETTINGS len=30, settings: MAX_FRAME_SIZE=1048576, MAX_CONCURRENT_STREAMS=250, MAX_HEADER_LIST_SIZE=1048896, HEADER_TABLE_SIZE=4096, INITIAL_WINDOW_SIZE=1048576
OverlayStream::Write called 39 <nil>
2024/01/20 19:06:25 http2: Framer 0xc0001de1c0: read SETTINGS len=18, settings: ENABLE_PUSH=0, INITIAL_WINDOW_SIZE=4194304, MAX_HEADER_LIST_SIZE=10485760
GossipMessageManager.SendToRemote called. dest: 00:00:00:00:9f:ab streamID: 10267
2024/01/20 19:06:25 http2: Framer 0xc0001de1c0: wrote WINDOW_UPDATE len=4 (conn) incr=983041
2024/01/20 19:06:25 http2: server read frame SETTINGS len=18, settings: ENABLE_PUSH=0, INITIAL_WINDOW_SIZE=4194304, MAX_HEADER_LIST_SIZE=10485760
OverlayStream::Write called 13 <nil>
2024/01/20 19:06:25 http2: server processing setting [ENABLE_PUSH = 0]
GossipMessageManager.SendToRemote called. dest: 00:00:00:00:9f:ab streamID: 10267
2024/01/20 19:06:25 http2: server processing setting [INITIAL_WINDOW_SIZE = 4194304]
2024/01/20 19:06:25 http2: server processing setting [MAX_HEADER_LIST_SIZE = 10485760]
2024/01/20 19:06:25 http2: Framer 0xc0001de1c0: wrote SETTINGS flags=ACK len=0
2024/01/20 19:06:25 http2: Framer 0xc0001de1c0: read WINDOW_UPDATE len=4 (conn) incr=1073741824
OverlayStream::Write called 9 <nil>
GossipMessageManager.onPacketReceived called. src: 00:00:00:00:9f:ab  streamId: 10267  bufSize: 28
2024/01/20 19:06:25 http2: server read frame WINDOW_UPDATE len=4 (conn) incr=1073741824
GossipMessageManager.SendToRemote called. dest: 00:00:00:00:9f:ab streamID: 10267
OverlayStream::Read called 0 <nil>
GossipSession.RemoteAddr called: 40875
0.0.0.0:20002
OverlayStream::RemoteAddr called  0.0.0.0:20002
GossipSession.RemoteAddr called: 40875
0.0.0.0:20002
2024/01/20 19:06:25 http2: server closing client connection; error reading frame from client 0.0.0.0:20002: short buffer ←★これが起きてしまう
クライアント側
PS C:\Data\work\gord-overlay> .\gordolctl.exe -l 127.0.0.1:20002 -n 127.0.0.1:20000
peerHost:  0.0.0.0:20002
NewOverlayPeer: peers= [127.0.0.1:20000]
join ring 127.0.0.1:20000
OverlayListener::Accept called 40875
DialContext tcp 127.0.0.1:20000
gossip> 2024/01/20 19:06:21 mesh router starting (40875)
time="2024-01-20T19:06:21+09:00" level=info msg="Running Gord server..."
time="2024-01-20T19:06:21+09:00" level=info msg="Gord is listening on 127.0.0.1:20002:20003"
gossip> 2024/01/20 19:06:21 Opening a stream to 30400
GossipMessageManager.SendToRemote called. dest: 00:00:00:00:76:c0 streamID: 10267
GossipMessageManager.SendToRemote: err: unknown relay destination: 00:00:00:00:76:c0
GossipMessageManager.onPacketReceived called. src: 00:00:00:00:76:c0  streamId: 10267  bufSize: 0
GossipMessageManager.SendToRemote called. dest: 00:00:00:00:76:c0 streamID: 10267
GossipMessageManager.onPacketReceived called. src: 00:00:00:00:76:c0  streamId: 10267  bufSize: 40
GossipMessageManager.SendToRemote called. dest: 00:00:00:00:76:c0 streamID: 10267
GossipMessageManager.onPacketReceived called. src: 00:00:00:00:76:c0  streamId: 10267  bufSize: 76
GossipMessageManager.SendToRemote called. dest: 00:00:00:00:76:c0 streamID: 10267
GossipMessageManager.onPacketReceived called. src: 00:00:00:00:76:c0  streamId: 10267  bufSize: 48
GossipMessageManager.SendToRemote called. dest: 00:00:00:00:76:c0 streamID: 10267
opened: 10267
GossipSession.RemoteAddr called: 30400
0.0.0.0:20002
OverlayStream::RemoteAddr called  0.0.0.0:20002
GossipSession.RemoteAddr called: 30400
0.0.0.0:20002
2024/01/20 19:06:22 http2: Transport creating client conn 0xc000436300 to 0.0.0.0:20002
GossipMessageManager.SendToRemote called. dest: 00:00:00:00:76:c0 streamID: 10267
GossipMessageManager.onPacketReceived called. src: 00:00:00:00:76:c0  streamId: 10267  bufSize: 16
2024/01/20 19:06:22 http2: Framer 0xc0004600e0: wrote SETTINGS len=18, settings: ENABLE_PUSH=0, INITIAL_WINDOW_SIZE=4194304, MAX_HEADER_LIST_SIZE=10485760
GossipMessageManager.onPacketReceived called. src: 00:00:00:00:76:c0  streamId: 10267  bufSize: 40
2024/01/20 19:06:22 http2: Framer 0xc0004600e0: wrote WINDOW_UPDATE len=4 (conn) incr=1073741824
OverlayStream::Write called 64 <nil>
GossipMessageManager.SendToRemote called. dest: 00:00:00:00:76:c0 streamID: 10267
2024/01/20 19:06:22 http2: Transport encoding header ":authority" = "127.0.0.1:20000"
2024/01/20 19:06:22 http2: Transport encoding header ":method" = "POST"
2024/01/20 19:06:22 http2: Transport encoding header ":path" = "/server.InternalService/FindSuccessorByTable"
2024/01/20 19:06:22 http2: Transport encoding header ":scheme" = "https"
2024/01/20 19:06:22 http2: Transport encoding header "connect-protocol-version" = "1"
2024/01/20 19:06:22 http2: Transport encoding header "content-type" = "application/proto"
2024/01/20 19:06:22 http2: Transport encoding header "accept-encoding" = "gzip"
2024/01/20 19:06:22 http2: Transport encoding header "connect-timeout-ms" = "180000"
2024/01/20 19:06:22 http2: Transport encoding header "user-agent" = "connect-go/1.14.0 (go1.21.2)"
2024/01/20 19:06:22 http2: Framer 0xc0004600e0: wrote HEADERS flags=END_HEADERS stream=3 len=132
OverlayStream::Write called 141 <nil>
GossipMessageManager.SendToRemote called. dest: 00:00:00:00:76:c0 streamID: 10267
2024/01/20 19:06:22 http2: Framer 0xc0004600e0: wrote DATA stream=3 len=34 data="\n \xab\x9f\x89X\x7fè\x02v\xf3\xee>x\xe2\xfcEq\x1c\xe2\x8bA\x06\x06@\x12%\xa4\x9d\xc2\xc6V\xf4"
OverlayStream::Write called 43 <nil>
2024/01/20 19:06:22 http2: Framer 0xc0004600e0: wrote DATA flags=END_STREAM stream=3 len=0 data=""
GossipMessageManager.SendToRemote called. dest: 00:00:00:00:76:c0 streamID: 10267
OverlayStream::Write called 9 <nil>
GossipMessageManager.SendToRemote called. dest: 00:00:00:00:76:c0 streamID: 10267
GossipMessageManager.SendToRemote called. dest: 00:00:00:00:76:c0 streamID: 10267
GossipMessageManager.onPacketReceived called. src: 00:00:00:00:76:c0  streamId: 10267  bufSize: 40
datachannel ERROR: 2024/01/20 19:06:25 Failed to handle DCEP: invalid Message Type &{0 0 0 [] []}
GossipMessageManager.onPacketReceived called. src: 00:00:00:00:76:c0  streamId: 10267  bufSize: 68
GossipMessageManager.SendToRemote called. dest: 00:00:00:00:76:c0 streamID: 10267
OverlayStream::Read called 39 <nil>
GossipMessageManager.onPacketReceived called. src: 00:00:00:00:76:c0  streamId: 10267  bufSize: 44
2024/01/20 19:06:25 http2: Framer 0xc0004600e0: read SETTINGS len=30, settings: MAX_FRAME_SIZE=1048576, MAX_CONCURRENT_STREAMS=250, MAX_HEADER_LIST_SIZE=1048896, HEADER_TABLE_SIZE=4096, INITIAL_WINDOW_SIZE=1048576
2024/01/20 19:06:25 http2: Transport received SETTINGS len=30, settings: MAX_FRAME_SIZE=1048576, MAX_CONCURRENT_STREAMS=250, MAX_HEADER_LIST_SIZE=1048896, HEADER_TABLE_SIZE=4096, INITIAL_WINDOW_SIZE=1048576
2024/01/20 19:06:25 http2: Framer 0xc0004600e0: wrote SETTINGS flags=ACK len=0
OverlayStream::Write called 9 <nil>
OverlayStream::Read called 13 <nil>
2024/01/20 19:06:25 http2: Framer 0xc0004600e0: read WINDOW_UPDATE len=4 (conn) incr=983041
2024/01/20 19:06:25 http2: Transport received WINDOW_UPDATE len=4 (conn) incr=983041
GossipMessageManager.SendToRemote called. dest: 00:00:00:00:76:c0 streamID: 10267
GossipMessageManager.onPacketReceived called. src: 00:00:00:00:76:c0  streamId: 10267  bufSize: 40
OverlayStream::Read called 9 <nil>
2024/01/20 19:06:25 http2: Framer 0xc0004600e0: read SETTINGS flags=ACK len=0
GossipMessageManager.SendToRemote called. dest: 00:00:00:00:76:c0 streamID: 10267
2024/01/20 19:06:25 http2: Transport received SETTINGS flags=ACK len=0
GossipMessageManager.onPacketReceived called. src: 00:00:00:00:76:c0  streamId: 10267  bufSize: 20
GossipMessageManager.onPacketReceived called. src: 00:00:00:00:76:c0  streamId: 10267  bufSize: 28
GossipMessageManager.onPacketReceived called. src: 00:00:00:00:76:c0  streamId: 10267  bufSize: 20
GossipMessageManager.onPacketReceived called. src: 00:00:00:00:76:c0  streamId: 10267  bufSize: 20
GossipMessageManager.SendToRemote called. dest: 00:00:00:00:76:c0 streamID: 10267
GossipMessageManager.onPacketReceived called. src: 00:00:00:00:76:c0  streamId: 10267  bufSize: 28
GossipMessageManager.SendToRemote called. dest: 00:00:00:00:76:c0 streamID: 10267
GossipMessageManager.onPacketReceived called. src: 00:00:00:00:76:c0  streamId: 10267  bufSize: 16
OverlayStream::Read called 0 <nil>
2024/01/20 19:06:29 http2: Transport readFrame error on conn 0xc000436300: (*errors.errorString) session closed
2024/01/20 19:06:29 http2: Framer 0xc0004600e0: wrote RST_STREAM stream=3 len=4 ErrCode=CANCEL
OverlayStream::Write called 0 stream closed
2024/01/20 19:06:29 RoundTrip failure: session closed ← ★クライアント側ではこうなる

デバッグログを眺めるに、自作ライブラリが、双方向の通信が入り乱れた場合（※）に、うまく通信できていないのではないか、というあたりが見えてきたが、原因は自身の書いたコードの範囲を確認した限りでは特に見当たらず困った・・・という感じである。
（見落としている可能性も大）

※一方がリクエストして、他方がレスポンスを返してというような単純な通信パターンでない（本当か？）

ryo_gridryo_grid

参考: 素直にTCPをトランスポートとして用いた時のHTTP2関連のデバッグ出力

サーバ側
PS C:\Data\work\gord-overlay> .\gordolctl.exe -l 127.0.0.1:20000
time="2024-01-19T21:14:13+09:00" level=info msg="Running Gord server..."
time="2024-01-19T21:14:13+09:00" level=info msg="Gord is listening on 127.0.0.1:20000:20001"
time="2024-01-19T21:14:13+09:00" level=info msg="Running Chord server..."
time="2024-01-19T21:14:13+09:00" level=info msg="Chord listening on 127.0.0.1:20000:20000"
2024/01/19 21:14:14 h2c: attempting h2c with prior knowledge.
2024/01/19 21:14:14 http2: server connection from 127.0.0.1:61533 on 0xc0000b8000
2024/01/19 21:14:14 http2: Framer 0xc0001f80e0: wrote SETTINGS len=30, settings: MAX_FRAME_SIZE=1048576, MAX_CONCURRENT_STREAMS=250, MAX_HEADER_LIST_SIZE=1048896, HEADER_TABLE_SIZE=4096, INITIAL_WINDOW_SIZE=1048576
2024/01/19 21:14:14 http2: Framer 0xc0001f80e0: read SETTINGS len=18, settings: ENABLE_PUSH=0, INITIAL_WINDOW_SIZE=4194304, MAX_HEADER_LIST_SIZE=10485760
2024/01/19 21:14:14 http2: Framer 0xc0001f80e0: wrote WINDOW_UPDATE len=4 (conn) incr=983041
2024/01/19 21:14:14 http2: server read frame SETTINGS len=18, settings: ENABLE_PUSH=0, INITIAL_WINDOW_SIZE=4194304, MAX_HEADER_LIST_SIZE=10485760
2024/01/19 21:14:14 http2: server processing setting [ENABLE_PUSH = 0]
2024/01/19 21:14:14 http2: server processing setting [INITIAL_WINDOW_SIZE = 4194304]
2024/01/19 21:14:14 http2: server processing setting [MAX_HEADER_LIST_SIZE = 10485760]
2024/01/19 21:14:14 http2: Framer 0xc0001f80e0: wrote SETTINGS flags=ACK len=0
2024/01/19 21:14:14 http2: Framer 0xc0001f80e0: read WINDOW_UPDATE len=4 (conn) incr=1073741824
2024/01/19 21:14:14 http2: server read frame WINDOW_UPDATE len=4 (conn) incr=1073741824
2024/01/19 21:14:14 http2: Framer 0xc0001f80e0: read HEADERS flags=END_HEADERS stream=3 len=121 ← overlayだとこれに失敗して、short bufferとか言っている感
2024/01/19 21:14:14 http2: decoded hpack field header field ":authority" = "127.0.0.1:20000"
2024/01/19 21:14:14 http2: decoded hpack field header field ":method" = "POST"
2024/01/19 21:14:14 http2: decoded hpack field header field ":path" = "/server.InternalService/Ping"
2024/01/19 21:14:14 http2: decoded hpack field header field ":scheme" = "https"
2024/01/19 21:14:14 http2: decoded hpack field header field "content-type" = "application/proto"
2024/01/19 21:14:14 http2: decoded hpack field header field "accept-encoding" = "gzip"
2024/01/19 21:14:14 http2: decoded hpack field header field "connect-timeout-ms" = "180000"
2024/01/19 21:14:14 http2: decoded hpack field header field "user-agent" = "connect-go/1.14.0 (go1.21.2)"
2024/01/19 21:14:14 http2: decoded hpack field header field "connect-protocol-version" = "1"
2024/01/19 21:14:14 http2: server read frame HEADERS flags=END_HEADERS stream=3 len=121
2024/01/19 21:14:14 http2: Framer 0xc0001f80e0: read DATA flags=END_STREAM stream=3 len=0 data=""
2024/01/19 21:14:14 http2: server read frame DATA flags=END_STREAM stream=3 len=0 data=""
2024/01/19 21:14:14 http2: Framer 0xc0001f80e0: read SETTINGS flags=ACK len=0
2024/01/19 21:14:14 http2: server read frame SETTINGS flags=ACK len=0
2024/01/19 21:14:14 http2: server encoding header ":status" = "200"
2024/01/19 21:14:14 http2: server encoding header "accept-encoding" = "gzip"
2024/01/19 21:14:14 http2: server encoding header "content-encoding" = "gzip"
2024/01/19 21:14:14 http2: server encoding header "content-type" = "application/proto"
2024/01/19 21:14:14 http2: server encoding header "content-length" = "23"
2024/01/19 21:14:14 http2: server encoding header "date" = "Fri, 19 Jan 2024 12:14:14 GMT"
2024/01/19 21:14:14 http2: Framer 0xc0001f80e0: wrote HEADERS flags=END_HEADERS stream=3 len=53
2024/01/19 21:14:14 http2: Framer 0xc0001f80e0: wrote DATA flags=END_STREAM stream=3 len=23 data="\x1f\x8b\b\x00\x00\x00\x00\x00\x00\xff\x01\x00\x00\xff\xff\x00\x00\x00\x00\x00\x00\x00\x00"
2024/01/19 21:14:14 h2c: attempting h2c with prior knowledge.
2024/01/19 21:14:14 http2: server connection from 127.0.0.1:61534 on 0xc0000b8000
2024/01/19 21:14:14 http2: Framer 0xc0002fe0e0: wrote SETTINGS len=30, settings: MAX_FRAME_SIZE=1048576, MAX_CONCURRENT_STREAMS=250, MAX_HEADER_LIST_SIZE=1048896, HEADER_TABLE_SIZE=4096, INITIAL_WINDOW_SIZE=1048576
2024/01/19 21:14:14 http2: Framer 0xc0002fe0e0: read SETTINGS len=18, settings: ENABLE_PUSH=0, INITIAL_WINDOW_SIZE=4194304, MAX_HEADER_LIST_SIZE=10485760
2024/01/19 21:14:14 http2: Framer 0xc0002fe0e0: wrote WINDOW_UPDATE len=4 (conn) incr=983041
2024/01/19 21:14:14 http2: server read frame SETTINGS len=18, settings: ENABLE_PUSH=0, INITIAL_WINDOW_SIZE=4194304, MAX_HEADER_LIST_SIZE=10485760
2024/01/19 21:14:14 http2: server processing setting [ENABLE_PUSH = 0]
2024/01/19 21:14:14 http2: server processing setting [INITIAL_WINDOW_SIZE = 4194304]
2024/01/19 21:14:14 http2: server processing setting [MAX_HEADER_LIST_SIZE = 10485760]
2024/01/19 21:14:14 http2: Framer 0xc0002fe0e0: wrote SETTINGS flags=ACK len=0
2024/01/19 21:14:14 http2: Framer 0xc0002fe0e0: read WINDOW_UPDATE len=4 (conn) incr=1073741824
2024/01/19 21:14:14 http2: server read frame WINDOW_UPDATE len=4 (conn) incr=1073741824
2024/01/19 21:14:14 http2: Framer 0xc0002fe0e0: read HEADERS flags=END_HEADERS stream=3 len=121
2024/01/19 21:14:14 http2: decoded hpack field header field ":authority" = "127.0.0.1:20000"
2024/01/19 21:14:14 http2: decoded hpack field header field ":method" = "POST"
2024/01/19 21:14:14 http2: decoded hpack field header field ":path" = "/server.InternalService/Ping"
2024/01/19 21:14:14 http2: decoded hpack field header field ":scheme" = "https"
2024/01/19 21:14:14 http2: decoded hpack field header field "connect-timeout-ms" = "180000"
2024/01/19 21:14:14 http2: decoded hpack field header field "user-agent" = "connect-go/1.14.0 (go1.21.2)"
2024/01/19 21:14:14 http2: decoded hpack field header field "connect-protocol-version" = "1"
2024/01/19 21:14:14 http2: decoded hpack field header field "content-type" = "application/proto"
2024/01/19 21:14:14 http2: decoded hpack field header field "accept-encoding" = "gzip"
2024/01/19 21:14:14 http2: server read frame HEADERS flags=END_HEADERS stream=3 len=121
2024/01/19 21:14:14 http2: Framer 0xc0002fe0e0: read DATA flags=END_STREAM stream=3 len=0 data=""
2024/01/19 21:14:14 http2: server read frame DATA flags=END_STREAM stream=3 len=0 data=""
2024/01/19 21:14:14 http2: Framer 0xc0002fe0e0: read SETTINGS flags=ACK len=0
2024/01/19 21:14:14 http2: server read frame SETTINGS flags=ACK len=0
2024/01/19 21:14:14 http2: server encoding header ":status" = "200"
2024/01/19 21:14:14 http2: server encoding header "accept-encoding" = "gzip"
2024/01/19 21:14:14 http2: server encoding header "content-encoding" = "gzip"
2024/01/19 21:14:14 http2: server encoding header "content-type" = "application/proto"
2024/01/19 21:14:14 http2: server encoding header "content-length" = "23"
2024/01/19 21:14:14 http2: server encoding header "date" = "Fri, 19 Jan 2024 12:14:14 GMT"
2024/01/19 21:14:14 http2: Framer 0xc0002fe0e0: wrote HEADERS flags=END_HEADERS stream=3 len=53
2024/01/19 21:14:14 http2: Framer 0xc0002fe0e0: wrote DATA flags=END_STREAM stream=3 len=23 data="\x1f\x8b\b\x00\x00\x00\x00\x00\x00\xff\x01\x00\x00\xff\xff\x00\x00\x00\x00\x00\x00\x00\x00"
クライアント側
PS C:\Data\work\gord-overlay> .\gordolctl.exe -l 127.0.0.1:20002 -n 127.0.0.1:20000
join ring 127.0.0.1:20000
DialContext tcp 127.0.0.1:20000
time="2024-01-19T21:14:24+09:00" level=info msg="Running Gord server..."
2024/01/19 21:14:24 http2: Transport creating client conn 0xc00033e000 to 127.0.0.1:20000
time="2024-01-19T21:14:24+09:00" level=info msg="Gord is listening on 127.0.0.1:20002:20003"
2024/01/19 21:14:24 http2: Framer 0xc000400000: wrote SETTINGS len=18, settings: ENABLE_PUSH=0, INITIAL_WINDOW_SIZE=4194304, MAX_HEADER_LIST_SIZE=10485760
2024/01/19 21:14:24 http2: Framer 0xc000400000: wrote WINDOW_UPDATE len=4 (conn) incr=1073741824
2024/01/19 21:14:24 http2: Transport encoding header ":authority" = "127.0.0.1:20000"
2024/01/19 21:14:24 http2: Transport encoding header ":method" = "POST"
2024/01/19 21:14:24 http2: Transport encoding header ":path" = "/server.InternalService/FindSuccessorByTable"
2024/01/19 21:14:24 http2: Transport encoding header ":scheme" = "https"
2024/01/19 21:14:24 http2: Transport encoding header "user-agent" = "connect-go/1.14.0 (go1.21.2)"
2024/01/19 21:14:24 http2: Transport encoding header "connect-protocol-version" = "1"
2024/01/19 21:14:24 http2: Transport encoding header "content-type" = "application/proto"
2024/01/19 21:14:24 http2: Framer 0xc000400000: read SETTINGS len=30, settings: MAX_FRAME_SIZE=1048576, MAX_CONCURRENT_STREAMS=250, MAX_HEADER_LIST_SIZE=1048896, HEADER_TABLE_SIZE=4096, INITIAL_WINDOW_SIZE=1048576
2024/01/19 21:14:24 http2: Transport received SETTINGS len=30, settings: MAX_FRAME_SIZE=1048576, MAX_CONCURRENT_STREAMS=250, MAX_HEADER_LIST_SIZE=1048896, HEADER_TABLE_SIZE=4096, INITIAL_WINDOW_SIZE=1048576
2024/01/19 21:14:24 http2: Transport encoding header "accept-encoding" = "gzip"
2024/01/19 21:14:24 http2: Transport encoding header "connect-timeout-ms" = "179999"
2024/01/19 21:14:24 http2: Framer 0xc000400000: wrote HEADERS flags=END_HEADERS stream=3 len=133
2024/01/19 21:14:24 http2: Framer 0xc000400000: wrote SETTINGS flags=ACK len=0
2024/01/19 21:14:24 http2: Framer 0xc000400000: read SETTINGS flags=ACK len=0
2024/01/19 21:14:24 http2: Transport received SETTINGS flags=ACK len=0
2024/01/19 21:14:24 http2: Framer 0xc000400000: wrote DATA stream=3 len=34 data="\n \xab\x9f\x89X\x7fè\x02v\xf3\xee>x\xe2\xfcEq\x1c\xe2\x8bA\x06\x06@\x12%\xa4\x9d\xc2\xc6V\xf4"
2024/01/19 21:14:24 http2: Framer 0xc000400000: wrote DATA flags=END_STREAM stream=3 len=0 data=""
2024/01/19 21:14:24 http2: Framer 0xc000400000: read WINDOW_UPDATE len=4 (conn) incr=983041
2024/01/19 21:14:24 http2: Transport received WINDOW_UPDATE len=4 (conn) incr=983041
2024/01/19 21:14:24 http2: Framer 0xc000400000: read HEADERS flags=END_HEADERS stream=3 len=53
2024/01/19 21:14:24 http2: decoded hpack field header field ":status" = "200"
2024/01/19 21:14:24 http2: decoded hpack field header field "accept-encoding" = "gzip"
2024/01/19 21:14:24 http2: decoded hpack field header field "content-encoding" = "gzip"
2024/01/19 21:14:24 http2: decoded hpack field header field "content-type" = "application/proto"
2024/01/19 21:14:24 http2: decoded hpack field header field "content-length" = "41"
2024/01/19 21:14:24 http2: decoded hpack field header field "date" = "Fri, 19 Jan 2024 12:14:24 GMT"
2024/01/19 21:14:24 http2: Transport received HEADERS flags=END_HEADERS stream=3 len=53
2024/01/19 21:14:24 http2: Framer 0xc000400000: read DATA flags=END_STREAM stream=3 len=41 data="\x1f\x8b\b\x00\x00\x00\x00\x00\x00\xff\xe2\xe2742\xd73\xd03\xd03\xb422000\x00\x04\x00\x00\xff\xff\x03\xe2?'\x11\x00\x00\x00"
2024/01/19 21:14:24 http2: Transport received DATA flags=END_STREAM stream=3 len=41 data="\x1f\x8b\b\x00\x00\x00\x00\x00\x00\xff\xe2\xe2742\xd73\xd03\xd03\xb422000\x00\x04\x00\x00\xff\xff\x03\xe2?'\x11\x00\x00\x00"
ryo_gridryo_grid

開発中のもののソフトウェアアーキ

今更ながら書いておく

ソフトウェアアーキ（?）
簡易な分散KVS（DHTによるルックアップとそれを用いた分散データストア機能）
256bit ID（レンジ） to オーバレイNW上の64bit ノードID マッピング by DHT（=ルックアップ）
ノード間のREST RPC呼び出し (Connectプロトコル。connect-go)
HTTP/1.x or HTTP/2
通信路の信頼性担保が加わったオーバレイNW（ryogrid/gossip-overlay lib）
データチャネル（WebRTC用のものを流用。pion/datachannel lib）
SCTP (信頼性のある通信路を提供するためのレイヤ。pion/sctp lib）
gossipプロトコルベースのNAT透過なオーバレイNW （weaveworks/mesh lib）
TCP（中継を行うものを含む個々のノード間の直接通信）
  • この中でも苦労させられたのはSCTPプロトコルでの通信を実装するために用いた pion/sctp である
    • サーバ・クライアント型の通信I/Fを提供するが、複数クライアントに対応していないことが途中で判明
    • どうにか手立てを調査・試行した結果、クライアント・クライアントという形で通信させても動くことが分った
      • 今の実装では、サーバ・クライアント型の通信アーキを提供するために、gossipプロトコルベースの（略）のレイヤ上に最低限の信頼性を担保した、クライアント側の情報（TCPやUDPでいうところのIPアドレスとポート番号相当）をサーバに伝えるパス？を用意
      • そのパスでクライアントがサーバに自身の情報を伝えて双方が相手の情報を知った状態にし、その上でクライアント・クライアントという形でのSCTPストリームを確立させるようなことをしている
    • pion/sctp はSCTP実装であるが、pion/webrtc というWebRTCのソフトウェアのために開発されたもののようで、 SCTP実装といってもWebRTCを実現するための範囲しか作りこまれていない
      • 開発途中でそこらへんの事情が読み取れてきた
      • 親ポチの理由からすると、サーバ側の実装に力が入っていないのも得心がいく（※1）し、同様の理由から、上のソフトウェアアーキの図にあるように本来無くても良い datachannel のレイヤがあったりする（※2）
        • ※1: 一つのIPアドレスで複数のクライアントと通信できなくても困らないような設計も想像がつく
        • ※2: pion/sctp が WebRTCを意識したI/Fを持っていたりしたために、正しく動かすには pion/datachannel を介するのが手っ取り早かった

補足（１）: "信頼性のある通信路を提供するオーバレイネットワーク"と書いてあるところ以下の処理は複数のライブラリを利用することで実現されているが、アプリケーションレイヤからするとgossip overlayライブラリだけ触れば良い作りになっている

補足（２）: オーバレイNWが2つあるが、どちらにおいてもノードのIDは同一。IPのようなデータグラム単位でのやりとりは下のやつでもできるが、それをベースにTCPのような信頼性のあるコネクションの形で扱えるI/Fを提供するようにしたものが上のやつ、という感じ

ちなみに、現在の問題の原因も、pion/sctp が想定通り動作していないため、という可能性がもしかするとあるかも、とか思っている。

ryo_gridryo_grid

以下への方針転換は無かったことになるかも。
　
ーーーーーーーーー
懸命にやったつもりですが、なかなかうまくいかず、結局DHTの利用、およびHTTP/2 化は断念しました・・・

代わりに weaveworks/meshのオーバレイの上であればDHTを使わない分散KVSをDHTとは別のアプローチで作れそう（元から考えてはいたけど）ということ考えていて、そちらをやってみようかと思っています。

  • DHTは stabilize の処理でどうしてもそれなりのオーバヘッドを要するやりとりをノード間で頻繁に行う必要がある
    • フルスクラッチで今回のオーバレイ上で動かす想定のものを作ればなんとかなるかもしれないが、そこまでの気合はない
  • これに対して、今考えているものは mesh ライブラリがよしなにノードリストを作ってくれているっぽいので、それを活用しようというもの
    • meshはgossipプロトコルベースでなのでそのあたりは効率的に行えている可能性がある
    • ただし、ノード数の規模が数千とかになったら多分筋悪なアプローチだろうとは思う
  • 簡易なデータストア機能回りだけであれば、gRPCやRESTインタフェースを使わずに、コネクション張りっぱなしでノード間のやりとりをするコードを自前で書けばよさそう（書けそう）
ryo_gridryo_grid

ちなみに、断念した方向性（DHT & HTTP/1.x）最終版の frame graph。
コネクションの確立が激遅というところにかかわってくるあたり。
2ノードだけのネットワークで、ノードで行われているのは定期的なstabilize処理だけ。
プロファイル時間は180秒。
グラフ上には80.98secと書いてあるので、約100秒はI/O待ち（RPC呼び出し先での処理含）ということでいいのかな・・・。
pprofのプロファイル結果の見方を正確に把握していないのはよくないなあ。

ryo_gridryo_grid

DHTベースのものはあきらめると書いたが、以下の方法でまだワンチャンあるかもしれないと思いついたので最後に試してみようと思っている

  • これまでいじっていたプログラム（分散KVSのノード）は、TCPを喋るだけの形にする
  • オーバレイNW上の通信を仲介できるプログラム（プロキシ的なもの）を用意する
    • 1対1かつ片方向の通信であれば既にポートフォワーディングツールを作った実績がある: gossip-port-forward
    • 双方向の通信が可能であるが、コネクションを張れる方向は2つのホスト上に立てたデーモンの関係性に従った一方向のみに限定される
    • 通信を転送する先のポートはノード起動時に指定したもの1つに限定される
  • 既存のものでは、ツール起動時に指定したIDを持つノード1つとしか通信ができないが、WebプロキシやSOCKSなどと同じように、プロキシに接続する際に、接続先の情報を最初に書き込ませるようにする
    • これは、いじっていたプログラムではトランスポートを自前のものに変えるということができているので、普通にできる

まあ、1ノードあたり2プロセスを立てる形になるのは取り回し的な観点でいまいちではあるのだけど、悪あがきということで。

ryo_gridryo_grid

既存のやつ（gossip-port-forward） を使って試してみたところ、

  • ノードA と ノードB がある
  • ノードB が ノードA のエンドポイントをコールするためにHTTP/2で通信してやりとりする

というのは動いた！
ということは、これを双方向でできるようにすれば2ノードだけであれば動くだろうし、多ノードに対応させれば、多分それもうまくいく？？？

ひとまず、自作ライブラリの実装において、1コネクションだけあった場合に、その中で双方向のやり取りが起きた場合に不具合が生じるわけではない、ということは上の結果から分かった。

ryo_gridryo_grid

以下でコネクションをプーリングしたHTTP/2 通信ができた!!! 2ノードだけのネットワークだけど！

  • 既存のやつ（gossip-port-forward） をさらに拡張し、宛先固定でサーバとクライアントの両方の役割をこなせるようにして、ノードA と ノードB の間ではHTTP/2の通信を通るようにした
  • プロキシを挟んでしまっているために、HTTP/2 のレイヤで見えるアドレスがノードAとノードBに対応するものでなく（※）なっていたので、そこをTCPListenerやらTCPConnクラスのラッパーを書いて、よしなに騙すようにした
    • プロキシの固定アドレスや、プロキシがフォワードする時に使う適当に選択されたポートでのアドレスに見えてしまっていた
    • HTTP/2の実装がコネクションの使いまわしをしてよいか否かを正しく判断できるようにするために、騙してやる必要があったのでは、と思っている
      • 騙すようにしたが、他の対処も入れてうまくいったわ、というのが現状で、これが本当に必要だったのかの検証まではできていない
  • http.Clientクラスオブジェクトの単純なプーリングを実装
    • Mapを使って、API呼び出しをしようとするノードのアドレスに対応する http.Client のオブジェクトが既にあったらそれを使いまわすというだけ
      • （コネクションが切断されてしまっている時に使い回さないという処理が素直に書けなかったので未対処。API呼び出しがエラーになった時の異常系で対処するかなぁ・・・）

これは勝ちが見えてきたか!

  • 動いた時のコードにしてあるブランチ
  • 動かす時のコマンドライン
    • ビルド
      • 各々のリポジトリルートで以下
        • ※: ryogrid/gossip-overlay が各々のリポジトリと同じディレクトリにcloneされていて、上記のブランチがcheckoutされている必要あり
      • go build -o gordolctl.exe main.go
      • go build -o gossip-port-forward.exe gossip-port-forward.go
    • ノードA（KVSでの初期ノード）
      • .\gossip-port-forward both -a 127.0.0.1 -f 20000 -s 1 -l 2222 -c 2
      • .\gordolctl.exe -l 127.0.0.1:20000 -p 127.0.0.1:2222
    • ノードB
      • .\gossip-port-forward both -a 127.0.0.1 -f 20002 -s 2 -l 2223 -c 1
      • .\gordolctl.exe -l 127.0.0.1:20002 -n 127.0.0.1:20000 -p 127.0.0.1:2223
    • 中継用ノード
      • （gossip-port-forward内にオーバレイNWに参加するためのブートストラップノードとしてアドレスがハードコードされている）
      • ryogrid.net のサーバで以下
      • $ ./gossip-port-forward relay -p 9999
        • ryogrid.net:9999 でlistenしていることになる
        • オーバレイNWでの通信の中継を行うが、過去に書いたソフトウェアアーキの図の下から2番目のところで関わってくるだけで、それより上層の処理がどうであろうとハンドルできる作りになっている
          • つまり、gossip-overlayライブラリを利用しているアプリケーションの通信であれば、アプリケーションの処理内容に関わらず中継できる。これは、gossip-overlayライブラリでオーバレイNWに参加しているプログラム全てにおいて同じ
          • 今回のケースだと、プロキシとしての役割を担わせている gossip-port-forward が該当
          • ただし、アプリケーションごとにネットワーク名をデフォルトのものから変更することはできて、異なる名前のネットワークに参加しているノードの通信はお互い中継しない（そもそも接続できない）
ryo_gridryo_grid

前回のやつの多ノード対応版も動いた！
これは勝つった！
　
やったこととしては下のような感じ。

  • プロキシ（のクライアント側の機能）は接続先のノードを知らないとフォワードできないので、分散KVSのアプリケーションにプロキシ接続後、最初に接続先のノード情報を書き込ませ、プロキシがよしなにそれを読んでフォワードするようにした
  • プロキシ（のサーバ側の機能）がローカルのアプリケーションへの接続をフォワードする際に、上と同じ要領で接続元ノードの情報を伝えさせるようにした
    • これは HTTP/2 のレイヤから見える接続元ホストを化かすため
      .
  • 動いた時のコード
  • コマンドライン
    • 1ノード目（KVS初期ノード）
      • .\gossip-port-forward both -a 127.0.0.1 -f 20000 -l 20002
      • .\gordolctl.exe -l 127.0.0.1:20000 -p 127.0.0.1:20002
    • 2ノード目
      • .\gossip-port-forward both -a 127.0.0.1 -f 20000 -l 20002
      • .\gordolctl.exe -l 127.0.0.1:20004 -n 127.0.0.1:20000 -p 127.0.0.1:20006
    • 3ノード目
      • .\gordolctl.exe -l 127.0.0.1:20008 -n 127.0.0.1:20004 -p 127.0.0.1:20010
      • .\gossip-port-forward both -a 127.0.0.1 -f 20008 -l 20010
    • 中継ノード
      • ryogrid.net のサーバで以下
      • $ ./gossip-port-forward relay -p 9999

.
これなら数十ノード程度ならまともなパフォーマンスで動くかも。
（データのレプリケーションとか実装してないけど・・・）
　
プロキシ通してええなら、以前作ったRust製の分散KVS（データのレプリケーションやらノード離脱・参加時の考慮も作りこんである）もオーバレイNW上で動かせると思うが、RESTする時にコネクションプールできないんだよな・・・。
（分散KVSの方の改修を）頑張れば、こっちもHTTP/2化とかできるかなあ。

ryo_gridryo_grid

docker-composeでお手軽に試せるようにしたし、最低限必要な情報？はリポジトリのREADMEに書いたので、この開発はこれぐらいで終わりにしようと思います。
興味のある方がいたらforkしてTODOに載せているあたりでも実装してもらえればありがたきです。
では、また次のネタをお楽しみに。

https://github.com/ryogrid/gord-overlay

ryo_gridryo_grid

gossip-overlay ライブラリもこんなもんかな、と思っていたところで、下のようなものを見つけてしまいました。

"yamux: Golang connection multiplexing library"
https://github.com/hashicorp/yamux

信頼性のある通信路を実現する方法として採用した結果、大分苦労させられた、かつ、今でもちょっと動作の怪しい pion/sctp よりこっちを利用した方が明らかに良さそうな感・・・