0
0

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?

macOS 49.7日問題(続編)― tcp_nowの変化をTCPタイムスタンプから探る

0
Posted at

前回の記事で、M4 Mac miniをデフォルトのエネルギー設定(自動スリープあり)で49.7日間連続稼働させても、ネットワーク障害が発生しないことを確認しました。

その際、次のように書きました。

想像ですが、スリープ中はtcp_now変数のカウントアップが止まっているのかもしれません。だとすると稼働時間が100日や150日くらいになったところで障害が発生するのかもしれません。

この「想像」を確かめたくなったので、続編として、実際にtcp_nowの挙動を追いかけてみた顛末を書きます。

今回はAIのClaudeさんに相談しながら進めました。最初に、「tcp_nowの値を直接見る方法はないか」と聞いたところ、DTraceでカーネル変数を直接読む方法を提案してくれました。いろいろな手段を試しましたが、結局はApple Silicon実機ではtcp_nowを読む出すことはできないという結論になりました。この顛末が以下の挑戦1です。

ここでClaudeから、そもそもなぜtcp_nowの値を知りたいのか尋ねられました。そこで前編の記事を示して、スリープ中にtcp_nowの値がどう変化するのか知りたいと説明しました。すると、TCPタイムスタンプの変化から、tcp_nowの変化を知る方法を提案してくれて、これが「なぜ49.7日問題がスリープ運用では起きにくいのか」の答えに至りました。その顛末が以下の挑戦2です。

挑戦1:DTraceでtcp_nowを直接見ようとした

tcp_nowはXNUカーネル内のグローバル変数(extern uint32_t tcp_now;)なので、まずはDTraceで直接覗けないか試しました。結論として、Apple Silicon Macでは、tcp_nowを読み出せないことがわかりました。以下は、その経緯です。興味のない方は次の「挑戦2」まで読み飛ばしてください。

DTraceには、バッククォートでカーネル内のグローバル変数を直接参照できる機能があります。

sudo dtrace -qn 'BEGIN { printf("tcp_now = %u\n", `tcp_now); exit(0); }'

ところが、これは動きませんでした。

dtrace: invalid probe specifier BEGIN { printf("tcp_now = %u\n", `tcp_now); exit(0); }: in action list: failed to resolve `tcp_now: Unknown symbol name

このエラーをそのままClaudeに伝えたところ、「macOSのSIP(System Integrity Protection)によってDTraceのカーネルメモリアクセスが制限されているのでは」と言われ、リカバリーモードで以下を実行するよう提案されました。

csrutil enable --without dtrace

言われた通りに実行し、再度同じdtraceコマンドを叩いてみましたが、結果はまったく同じエラーでした。ここから、Claudeと一緒に原因を切り分けていくことになります。原因を探るうちに、いくつかのことがわかりました。

  • macOSのリリース版カーネルは、tcp_nowのようなグローバル変数のシンボルをあらかじめ削除(strip)してあり、DTraceのバッククォート構文では解決できない
  • シンボル付きのカーネル(development/debugカーネル)に切り替えれば読めるはずだが、そのためにはApple公式の Kernel Debug Kit (KDK) が必要
  • ところが、Apple Silicon実機ではdevelopment/debugカーネルへの切り替えそのものがサポートされていない(KDKのREADMEにも明記されている)。動作実績があるのはUTM等の仮想マシン上のmacOSのみで、M4 Mac miniのようなベアメタル環境では成立しない

つまり、M4 Mac mini実機のままでは、DTraceでtcp_nowを直接読むルートは事実上詰みでした。SIPを解除しても、KDKを入れても、実機である限りどうにもならないというのは、Claudeさんにとっても、やってみるまでわからないことのようでした。試しても出来ないことで、AIが自分の誤りに気づいてくれて、正しい結論に到達できる——というのは面白い体験でした。

挑戦2:TCPタイムスタンプオプションから間接的に探る

tcp_nowを読む手段が無いと分かったところで、Claudeから、そもそもなぜtcp_nowの値を知りたいのか尋ねられました。そこで前編の記事を示して、スリープ中にtcp_nowの値がどう変化するのか知りたいと説明しました。

すると、「tcp_nowを直接読めなくても、TCPパケットのタイムスタンプオプションの値から間接的に推測できるかもしれない」という提案がありました。tcp_nowを直接読めなくても、TCPパケットのタイムスタンプオプション(TSオプション、RFC 1323 / RFC 7323)の値が、tcp_nowを元に生成されていることを利用すれば、パケットキャプチャだけでtcp_nowの進み方を間接的に観測できるはずとのことです。

TCPのタイムスタンプオプションには、TSval(送信側のタイムスタンプクロックの現在値)とTSecr(相手から受け取ったTSvalのエコーバック)という2つのフィールドがあります。macOSのTCPスタックでは、このTSvalの値の元になっているのがまさにtcp_nowです。

ただし、RFC 7323にはこう書かれています。

A random offset may be added to the timestamp clock on a per-connection basis.

つまり、そのままtcp_nowの値が出てくるわけではなく、コネクションごとにランダムなオフセットが加算された値がTSvalとして出てくわけです。つまり、同一のコネクションならば、

TSval = tcp_now + (一定のオフセット)

という関係になります。これを踏まえて、以下の実験を行いました。

実験方法

用意したのは以下の2台です。

  • 検証対象:スリープさせるM4 Mac mini, macOS Tahoe 26.5.2(IP: 192.168.xxx.6)
  • 観測役:古いIntel MacBook Pro、macOS Catalina(IP: 192.168.xxx.138)

同一のコネクションであればオフセットが変化しないため、スリープの前後で同じTCPコネクションを維持したまま、その中のTSvalの変化を追うことにしました。

(1) Mac miniからMacBook ProへSSH接続し、放置する

ssh -o ServerAliveInterval=30 192.168.xxx.138

ServerAliveInterval=30により、30秒ごとにKeepaliveパケットが飛びます。ログイン後はそのまま放置します。

(2) MacBook Pro側でスリープ前のパケットをキャプチャする

sudo tcpdump -i en1 -tt -vv 'host 192.168.xxx.6 and tcp' -w before_sleep.pcap

MacBook Proでは、WiFiを使っているので、en1を指定してます。2分ほど記録してCtrl-Cで停止。30秒間隔のKeepaliveパケットがちゃんと記録されていました。

(3) Mac miniをスリープさせる

2026年7月28日 00時11分22秒 JSTから、同日12時57分17秒 JSTまで、45,955秒(約12.8時間)スリープさせました。

(4) スリープ復帰後、MacBook Pro側で再度パケットをキャプチャする

sudo tcpdump -i en1 -tt -vv 'host 192.168.xxx.6 and tcp' -w after_sleep.pcap

(5) TSvalを比較する

キャプチャした2つのpcapファイルから、以下のようにすると30秒ごとのKeepaliveパケットの記録を取り出せました。MacBookにやってくるsshパケットのうち、長さが52のものが該当するもののようです。

tcpdump -r before_sleep.pcap -vv | grep "> 192.168.xxx.138.ssh" | grep "length 52"

この結果、

reading from file before_sleep.pcap, link-type EN10MB (Ethernet)
    192.168.xxx.6.49926 > 192.168.xxx.138.ssh: Flags [P.], cksum 0xc446 (correct), seq 1520855565:1520855617, ack 1492452546, win 2048, options [nop,nop,TS val 2782492122 ecr 969629256], length 52
    192.168.xxx.6.49926 > 192.168.xxx.138.ssh: Flags [P.], cksum 0x3c8c (correct), seq 52:104, ack 37, win 2048, options [nop,nop,TS val 2782522122 ecr 969658976], length 52
    192.168.xxx.6.49926 > 192.168.xxx.138.ssh: Flags [P.], cksum 0xca3e (correct), seq 104:156, ack 73, win 2048, options [nop,nop,TS val 2782552119 ecr 969688972], length 52

という結果が得られます。3個のkeepaliveパケットが来ていて、そのTSvalがほぼ30秒間隔であることがわかります。このようにして、before_sleep.pcapの最後のパケットと、after_sleep.pcapの最初のパケットのTSvalを書き留めます。これらは、同一のSSHコネクション(送信元ポート固定)のTSvalとなります。

時刻 TSval
スリープ前 最終パケット 2026-07-28 00:10:55 JST 2782552119
スリープ後 最初のパケット 2026-07-28 12:58:17 JST 2801057206

このTSvalの差が、スリープ前後のtcp_nowの差になります。それを実際の時間と比較すると以下になります。

  • TSvalの差分:2801057206 - 2782552119 = 18,505,087 ミリ秒 ≈ 18,505秒
  • 実時間の差分:45,955秒
  • 比率:18,505 / 45,955 ≈ 40.3%

実時間は約4万6千秒経過したのに、TSval(≒tcp_now)は約1万8千秒しか進んでいませんでした。 つまり、スリープ中はtcp_nowの進み方が明らかに遅くなっている、ということが確認できました。

同様の実験を、約2時間のスリープでも行ったところ、こちらは比率が 約63% でした。スリープ時間の長さによって比率が変わるようです。

考察

完全な「停止」ではなく「進行速度の低下」

もしtcp_nowの更新がスリープ中に完全に停止するのであれば、この比率はもっと小さくなるはずです(スリープが大半を占める12.8時間のうち、覚醒していた時間の割合程度になるはず)。40%や63%という値は、それよりずっと高いです。

考えられる理由は、macOSの Power Nap(dark wake) です。スリープ中でも定期的に短時間だけ低電力状態から復帰し、メールやiCloudの同期などを行う仕組みがあります。このdark wake中はタイマー類が通常通り動作しtcp_nowも進む一方、それ以外の深いスリープ中は進行が鈍る(あるいは止まる)——という断続的な動きが、全体として「進むが実時間よりゆっくり」という中間的な比率になって現れているのではないかと推測しています。

実際、スリープ中に取得したパケットキャプチャでは、本来30秒間隔のはずのKeepaliveパケットが40秒以上の間隔でばらついて記録されていました。これも、dark wakeのタイミングでまとめてパケットが送出される、という挙動と辻褄が合います。

TSvalオフセットの実在も確認できた

余談ですが、after_sleep.pcapの中に、たまたま別のTCPコネクション(MacBook Proの別ポートから、Mac miniの別ポートへのSYNパケット)が記録されていました。このコネクションのTSvalは3629268421と、SSHコネクションのTSval(2801...台)とはまったく異なる値でした。

同じMac miniから出ているパケットなのに、コネクションが違うとTSvalの値も全然違う——これはまさに、RFC 7323が推奨する「コネクションごとのランダムオフセット」が実際に実装されていることの証拠です。逆に言えば、もし異なるコネクション同士でTSvalを比較していたら、誤った結論を導いていたところでした。今回、同一コネクションを維持したまま前後比較するという実験設計にしておいて正解でした。

49.7日問題が実際に起きるとしたら

今回得られた2つの比率(12.8時間スリープで40%、2時間スリープの場合63%)を単純に外挿すると、

  • 比率40%なら:49.7日 ÷ 0.40 ≈ 124日
  • 比率63%なら:49.7日 ÷ 0.63 ≈ 79日

となり、前回の記事で書いた「100日や150日くらい」という想像は、そう遠くなかったようです。

ただしこの数字は、期間中スリープしていた場合の値です。実際にどれくらいの比率でtcp_nowが進むかは、日々どれくらいスリープさせているか、Power Napの頻度設定など、Macの使い方に強く依存します。より正確な予測をしようとすると、結局「あなたの使い方次第です」としか言えなくなってしまうので、今回の調査はここで一区切りとしたいと思います。

まとめ

  • Apple Silicon実機では、development/debugカーネルへの切り替え(DTraceでのカーネル変数直接読み取り)はサポートされておらず、tcp_nowを直接読むことはできなかった
  • 代わりにTCPタイムスタンプオプション(TSval)を使い、同一コネクションを維持したままスリープ前後で値を比較する方法で、間接的にtcp_nowの挙動を観測できた
  • スリープ中もtcp_nowは完全には止まっておらず、実時間の40〜63%程度の速度で進んでいるようだった(Power Nap / dark wakeの影響と推測)
  • この結果、49.7日問題がデフォルト設定(自動スリープあり)の運用で顕在化するとすれば、単純計算で80日〜124日程度先になりそうだが、実際の日数は使い方次第で変わる
  • TCPタイムスタンプオプションには、RFC 7323で推奨されているとおり、コネクションごとにランダムなオフセットが加算されていることも実際のパケットで確認できた

今回の調査は、Claudeに相談しながら進めました。最初はDTraceを使う方法を提案されましたが、エラーが出てくるたびに、Claudeが次の一手を考え、最終的に「実機のApple Siliconでは無理」という結論に辿り着きました。そもそもなぜtcp_nowを知りたいのかを聞いてきたのもClaudeですし、それに対して、「パケットのタイムスタンプオプションから間接的に観察する」という代替案を出してくれました。私は、tcpdumpコマンドを使って解析しましたが、ClaudeはPythonプログラムを作成して解析して、結果が同じことを確認してくれました。正直「Claudeすごい」と思いました。


さらには、ここまでのブログの文章も、実はClaudeさんにMarkdown形式で作ってもらってます。結果に多少手を入れましたが、ほぼ90%以上、回答されたままの文章です。AIはすごいと思いました。

0
0
0

Register as a new user and use Qiita more conveniently

  1. You get articles that match your needs
  2. You can efficiently read back useful information
  3. You can use dark theme
What you can do with signing up
0
0

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?