Zenn
😽

TCP keepalive は再送中のパケットがある場合は動作を開始しないことの確認

2024/08/17に公開
Linux
tcp
keepalive
tech

以下記事で出てきたTCP keepalive機能の動作確認です。

https://blog.cybozu.io/entry/2015/11/26/170019

過去に記事を見て「へー」と思っていたんですけれども、「実際に見もせずにわかった気になるのはよくないな！」と記事を読んでから5年後くらいの今、突然思い立って動作確認することにしました。確認したかったのは、タイトル通り「TCP keepalive は再送中のパケットがある場合は動作を開始しない」ことです。こういう挙動だと何がまずいのかとかいう詳しいところは元記事を参照してほしいです。

実験環境

マシンは以下2つを使いました。

  • coffee(以下、サーバマシン)。OSはUbuntu 22.04、カーネルはv5.15.0-117-generic。
  • tea(以下、クライアントマシン)。OSはUbuntu 22.04、カーネルはv5.15.0-107-generic。

サーバマシンとクライアントマシン上ではそれぞれTCPで通信するserver.pyとclient.pyを動かしました。

server.pyはclient.pyからの接続を待ち受け、送られてきたデータを出力した後に同じデータを送り返して終了するというものです。

server.py
import socket
from datetime import datetime

HOST = "0.0.0.0"
PORT = 10000

with socket.socket(socket.AF_INET, socket.SOCK_STREAM) as s:
    s.bind((HOST, PORT))
    s.listen()
    print(f"{datetime.now()}: listening {HOST}:{PORT}.")

    conn, addr = s.accept()
    with conn:
        print(f"{datetime.now()}: connected from {addr}.")
        try:
            data = conn.recv(1024)
            print(f"{datetime.now()}: received `{data.decode()}`.")
            conn.sendall(data)
        except (socket.error, OSError) as e:
            print(f"{datetime.now()}: {e}.")

client.pyはserver.pyに接続してユーザからのENTERキーの入力を待ち、入力されてから5秒後にserver.pyにメッセージを送り、戻ってきたメッセージを出力して終了します。何らかの事情で10秒以上クライアントマシンとサーバマシンとの間で通信ができない状態が続くとコネクションを自動的にクローズするようなTCP keepaliveの設定をソケットにしています。

client.py
import socket
import time
from datetime import datetime

HOST = "192.168.1.100" # サーバ(coffee)のIPアドレス
PORT = 10000

with socket.socket(socket.AF_INET, socket.SOCK_STREAM) as s:
    s.setsockopt(socket.SOL_SOCKET, socket.SO_KEEPALIVE, 1)
    s.setsockopt(socket.IPPROTO_TCP, socket.TCP_KEEPIDLE, 5) # ★1
    s.setsockopt(socket.IPPROTO_TCP, socket.TCP_KEEPINTVL, 5) # ★2
    s.setsockopt(socket.IPPROTO_TCP, socket.TCP_KEEPCNT, 2) # ★3
    s.connect((HOST, PORT))
    print(f"{datetime.now()}: connected to the server. The timeout for this TCP connection is 10 seconds.")
    print(f"{datetime.now()}: press enter.")
    input()
    for i in range(5):
        print(f"{datetime.now()}: send a message to the server after {5-i} seconds.")
        time.sleep(1)
    print(f"{datetime.now()}: send a message now.")
    try:
        s.sendall(b"hello!")
        data = s.recv(1024)
        print(f"{datetime.now()}: received `{data.decode()}`")
    except (socket.error, OSError) as e:
        print(f"{datetime.now()}: {e}")

より正確にいうとclient.pyとserver.pyとの間で通信が全く無い状態で5秒(★1)経過すると、クライアントマシンのカーネルからサーバマシンのカーネルに自動的にTCP keepalive用のパケットが送られ、さらに5秒後(★)にまた応答が無い場合、連続2回(★3)応答が無い場合にコネクションをクローズします。単に10秒間通信をしていないだけだとカーネルレベルでの通信は成功しますので、コネクションはクローズしません。コネクションをクローズするのは、あくまでサーバマシンが落ちたときやサーバマシンに至るまでのネットワーク障害などによって、2つのマシンがカーネルレベルで通信ができない場合のみです。

正常動作を確認

まずはTCP keepaliveを一切考えない、正常時の挙動を確認してみましょう。

最初にサーバマシン上でserver.pyを起動させます。

sat@coffee:~/src/pysock$ python3 server.py
2024-08-17 22:48:16.024905: listening 0.0.0.0:10000. ★ client.pyからの接続待ち

この後クライアントマシン上でclient.pyを起動させた後に、すぐにENTERを押下すると、5秒後に自分が送ったメッセージが返ってきて終了します。

sat@tea:~/src/pysock$ python3 client.py
2024-08-17 22:48:22.343592: connected to the server. The timeout for this TCP connection is 10 seconds.
2024-08-17 22:48:22.343687: press enter. ★ ここでENTERを押下

2024-08-17 22:48:23.907758: send a message to the server after 5 seconds.
2024-08-17 22:48:24.908998: send a message to the server after 4 seconds.
2024-08-17 22:48:25.910346: send a message to the server after 3 seconds.
2024-08-17 22:48:26.911842: send a message to the server after 2 seconds.
2024-08-17 22:48:27.913317: send a message to the server after 1 seconds.
2024-08-17 22:48:28.914752: send a message now. ★ serverlpyへのメッセージの送信
2024-08-17 22:48:28.917909: received `hello!` ★ 直後に自分が送ったメッセージがserver.pyから送り返されたことを確認

server.pyの出力からも、client.pyから接続された後にメッセージを受け取ったことがわかります。

sat@coffee:~/src/pysock$ python3 server.py
2024-08-17 22:48:16.024905: listening 0.0.0.0:10000.
2024-08-17 22:48:22.345484: connected from ('192.168.1.101', 64450). ★ client.pyから接続された
2024-08-17 22:48:28.917482: received `hello!`. ★ client.pyからメッセージを受信した

よくある、何の面白みもないプログラムです。

TCP keepaliveのタイムアウトを発生させる方法

さて、ここからTCP keepaliveの動作確認をするために「何らかの事情で10秒以上クライアントマシンとサーバマシンとの間で通信ができない状態」を作り出す必要があります。方法はいろいろ考えられますが、本記事では筆者が過去に作った、所定の期間Linuxの時間を止めるカーネルモジュール、stop-machineを使います。stop-machineを使ってサーバマシンを30秒間、TCP/IP通信も含めて何もできない状態にします。

stop-machineがどういう作りなのかは本記事のスコープ外なので説明は省略しますが、知りたいかたは、ちょっと古いバージョンについて述べたものですが、以下の記事をごらんくらだい。

https://zenn.dev/satoru_takeuchi/articles/f068e979dad99cc5230b

動画のほうがいいかたは以下youtube動画を見てください。

https://youtu.be/OYvhXQLfBmw

TCP keepaliveを発生させる

以下のような手順で確認します。

  1. サーバマシン上でserver.pyを実行開始。
  2. クライアントマシン上でclient.pyを実行開始。
  3. サーバマシン上で別端末からstop-machineをロードする。このあとサーバマシンはTCP/IP通信を含め30秒間何もできない状態になる。
  4. stop-machineによる通信不能状態が解消されてから、クライアントマシン上でENTERを押下してserver.pyにメッセージを送る。

以下、実行結果です。

1. サーバマシン上でserver.pyを実行開始。

sat@coffee:~/src/pysock$ python3 server.py
2024-08-17 22:51:22.606357: listening 0.0.0.0:10000.

2. クライアントマシン上でclient.pyを実行開始。

sat@tea:~/src/pysock$ python3 client.py
2024-08-17 22:51:24.447714: connected to the server. The timeout for this TCP connection is 10 seconds.
2024-08-17 22:51:24.447788: press enter.

サーバマシン上のserver.pyにclient.pyから接続されたことが以下の★部分からわかります。

sat@coffee:~/src/pysock$ python3 server.py
2024-08-17 22:51:22.606357: listening 0.0.0.0:10000.
2024-08-17 22:51:24.452076: connected from ('192.168.1.101', 64486). ★

3. サーバマシン上で別端末からstop-machineをロードする。このあとサーバマシンはTCP/IP通信を含め30秒間何もできない状態になる。

sat@coffee:~/src/youtube-sample/0079-stop-machine$ date; sudo insmod stop-machine.ko ; date; sudo rmmod stop-machine
Sat Aug 17 22:51:28 JST 2024
Sat Aug 17 22:51:58 JST 2024 ★
sat@coffee:~/src/youtube-sample/0079-stop-machine$

★より、モジュールのロードから30秒後にサーバマシンがまた動作できるようになり、dateが実行されたことがわかります。ここで通信ができない状態も解消しています。

4. stop-machineによる通信不能状態が解消されてから、クライアントマシン上でENTERを押してserver.pyにメッセージを送る。

sat@tea:~/src/pysock$ python3 client.py
2024-08-17 22:51:24.447714: connected to the server. The timeout for this TCP connection is 10 seconds.
2024-08-17 22:51:24.447788: press enter.
  ★1 
2024-08-17 22:52:01.371441: send a message to the server after 5 seconds.
2024-08-17 22:52:02.372816: send a message to the server after 4 seconds.
2024-08-17 22:52:03.374325: send a message to the server after 3 seconds.
2024-08-17 22:52:04.375704: send a message to the server after 2 seconds.
2024-08-17 22:52:05.376974: send a message to the server after 1 seconds.
2024-08-17 22:52:06.378544: send a message now.
2024-08-17 22:52:06.378748: [Errno 110] Connection timed out ★2

通信途絶が解消した22:51:58 より後にENTERを押下したことが★1からわかります。その後、メッセージを送ろうとしたところ★2においてコネクションがタイムアウトして閉じられたことを検出しました。

TCP keepaliveの機能によって、以下のような流れでコネクションがcloseされたはずです。

  1. クライアントマシン上でclient.pyが22:51:24に、ユーザにENTERキーの入力を促した。
  2. 22:51:28から22:51:58までサーバマシンが通信ができない状態になっていた。
  3. クライアントマシン上でENTERキーの入力を待ちだしてから5秒後の22:51:29ごろに、TCP keepalive用の最初のパケットがサーバマシンに送られるが、応答なし。
  4. さらに5秒後の22:51:34ごろに、TCP keepalive用の2回目のパケットをサーバマシンに送るも、応答なし。コネクションをクローズ。
  5. 22:52:06にclient.pyからserver.pyにメッセージを送ろうとするも、既にコネクションが切れているのでエラー発生。

サーバマシン上のserver.pyは、stop-machineによって通信ができなくなっていた期間が終わった瞬間に、クライアントからコネクションが閉じられたことを、以下★部分で検出しています。

sat@coffee:~/src/pysock$ python3 server.py
2024-08-17 22:51:22.606357: listening 0.0.0.0:10000.
2024-08-17 22:51:24.452076: connected from ('192.168.1.101', 64486).
2024-08-17 22:51:58.095116: [Errno 104] Connection reset by peer. ★

正確なところはtcmdumpなりを使ってクライアントからRSTが送られてることを確認するほうがよいのですが、横着しました。後日気が向けば追記するかもです。

TCP keepalive は再送中のパケットがある場合は動作を開始しないことの確認

以下のような手順で確認します。

  1. サーバマシン上でserver.pyを実行開始。
  2. クライアントマシン上でclient.pyを実行開始。
  3. サーバマシン上でstop-machineをロードする。このあとサーバマシンはTCP/IP通信を含め30秒間何もできない状態になる。
  4. stop-machineによる通信不能状態が始まって数秒以内に、クライアントマシン上でENTERを押下してserver.pyにメッセージを送る。

以下、実行結果です。

1. サーバマシン上でserver.pyを実行開始。

sat@coffee:~/src/pysock$ python3 server.py
2024-08-17 23:13:00.823749: listening 0.0.0.0:10000.

2. クライアントマシン上でclient.pyを実行開始。

sat@tea:~/src/pysock$ python3 client.py
2024-08-17 23:13:03.747984: connected to the server. The timeout for this TCP connection is 10 seconds.
2024-08-17 23:13:03.748049: press enter.

3. サーバマシン上でstop-machineをロードする。このあとサーバマシンはTCP/IP通信を含め30秒間何もできない状態になる。

sat@coffee:~/src/youtube-sample/0079-stop-machine$ date; sudo insmod stop-machine.ko ; date; sudo rmmod stop-machine
Sat Aug 17 23:13:10 JST 2024
Sat Aug 17 23:13:39 JST 2024

4. stop-machineによる通信不能状態が始まって数秒以内に、クライアントマシン上でENTERキーを押下してserver.pyにメッセージを送る。

以下クライアント側の出力です。

sat@tea:~/src/pysock$ python3 client.py
2024-08-17 23:13:03.747984: connected to the server. The timeout for this TCP connection is 10 seconds.
2024-08-17 23:13:03.748049: press enter.
 ★1 
2024-08-17 23:13:11.778472: send a message to the server after 5 seconds.
2024-08-17 23:13:12.779654: send a message to the server after 4 seconds.
2024-08-17 23:13:13.781161: send a message to the server after 3 seconds.
2024-08-17 23:13:14.782496: send a message to the server after 2 seconds.
2024-08-17 23:13:15.783985: send a message to the server after 1 seconds.
2024-08-17 23:13:16.785534: send a message now.
2024-08-17 23:13:39.820123: received `hello!` ★2

サーバマシンへの通信ができない23:13:10ごろから23:13:39ごろの間である23:13:11ごろにENTERを押下したことが★1からわかります。その後、TCP keepaliveによるタイムアウト時間10秒をはるかに超える、およそ28秒後にserverlpyとのメッセージ送受信が完了したことが★2を見ればわかります。

こちらも本来はサーバマシンへの通信ができない間にクライアントからのパケットが再送され続けていることをtcmpdumpなりで確認するほうがいいのですが、横着しました。

おわりに

上記の動作確認をやろうとしたときは「こんな程度の確認は20分程度あれば終わるだろう」と高をくくっていました。しかし、蓋を開けてみると、どういう設定で何をどういう順番で動かせば挙動を確認できるのか、という基本的なところに手間取ってしまい、結局2,3時間を費やしました。理解したつもりで大して理解していなかったのでしょう。実際に試してみることによって、理解がクリアになった、やってよかったと思います。一か月後には忘れてそうですが、そういうときはこの記事を見返せばよいのです。ということで、おわり。

Discussion