この記事は、ゆるWeb勉強会@札幌 Advent Calendar 2022の23日目です。今回も開発環境(?)の話です。
要約
macOS Monterey (12.6.2)をスリープから復帰させた後に、直前までテザリングしていたiPhoneでもう一度テザリングしようと試みたところ、接続エラーが発生するトラブルに見舞われました。
再接続も繰り返すもうまくいかず、毎回再現するようになってしまったのでログを含めて調査したところ、bluetoothd を再起動すれば解決する ことがわかりました。
sudo launchctl kickstart -k system/com.apple.bluetoothd
トラブル時はログを見るのが大事 ですね。
なお、このトラブルはおそらく私が bluesnooze を使っているからなので、多くの方は同様の問題に陥らないのではと思いますが、色々調べた・試した内容を備忘録として残しておきます。
やってみたこと
✅(改善される)macOSX or iPhoneの再起動
解決するが、毎回再起動の時間を待つのはいささか面倒なので、他の方法を探したいなとなりました。
🚫(改善されない)ネットワークインターフェースの再起動
接続エラーの時、ネットワークインターフェースは inactive になっていました。
なので、ネットワークインターフェースを再起動してみたらどうでしょうか。
GUI上からWi-FiをON/OFFしてみたり、コマンドで再起動してみましたが、
sudo ifconfig en0 down
sudo ifconfig en0 up
再接続できない状況は改善しませんでした。
🚫(解決されない)BluetoothのON/OFF
iPhoneとmac OSのテザリングであれば、Bluetoothを経由している可能性があるなと思い、Bluetoothをシステム環境設定から切・入してみました。
こちらも、再接続できない状況は改善しませんでした。
🔎 ログを見る
ネットワークインターフェースの再起動や、GUI上からのWi-Fi・BluetoothのON/OFFではダメだけど、OSレベルの再起動で改善するのなら、大元のDaemonあたりが何かトラブルの原因になっているのでは、と推察しました。
これも当てずっぽうに探すのは大変なので、コンソール.appでログを追いながら、再接続できない時と、うまく再接続できる時(再起動などをした場合)のログを比較すると、以下の様な違いがあることがわかりました。
接続エラーが発生する際のログ: 分かりやすい様に一部改行しています。
rapportd Start on-demand connection (ForceL2CAP) to IDS ...
sharingd Activated: CLinkClient, CID ...
sharingd XXXXXXXX: Companion link client activated for device: IDS ...
bluetoothd Device connecting - {cbuuid: ...
WiFiAgent Enabled <SFRemoteHotspotDevice: 0xXXXXXXXXX...
(null), error (Error Domain=RPErrorDomain Code=-71143
"kNetworkErr (Connect failed)" UserInfo={NSUnderlyingError=0xXXXXXXXXX
{Error Domain=CBErrorDomain Code=15 "Failed to encrypt the connection,
the connection has timed out unexpectedly."
UserInfo={NSLocalizedDescription=Failed to encrypt the connection,
the connection has timed out unexpectedly.}},
cuErrorDesc=kNetworkErr (Connect failed),
cuErrorMsg=Connect failed,
NSLocalizedDescription=kNetworkErr (Connect failed)})
改善されている時のログ:
rapportd Start on-demand connection (ForceL2CAP) to IDS ...
sharingd Activated: CLinkClient, CID ...
sharingd XXXXXXXX: Companion link client activated for device: IDS ...
bluetoothd Device connecting - {cbuuid: ...
bluetoothd Device ready - {cbuuid: ...
bluetoothd Device found: CBDevice ...
cloudpaird Pairing found device CBDevice ...
rapportd CLinkCnx-47: DidOpenL2CAPChannel <CBL2CAPChannel: 0xXXXXXXXXX ...
rapportd Resolved identity for signature: owner, RPIdentity, Type SameAccountDevice, IDS ...
rapportd 47: PairVerify completed client (RPI-Owner), ...
bluetoothd Device found: CBDevice...
cloudpaird Pairing found device CBDevice ...
sharingd XXXXXXXX: Request complete: success with info: <SFRemoteHotspotInfo: ...
WiFiAgent Enabled <SFRemoteHotspotDevice: 0xXXXXXXXX, ..., error ((null))
両者とも4行目から bluetoothd Device connecting
が動いているようです。
しかし、接続エラーとなる場合はその後 WiFiAgent
が動き出し、エラーとして kNetworkErr (Connect failed)
が発生しているようです。
改善されているときは、bluetoothd
がそのまま Device ready
, Device found
を進め、それに呼応して cloudpaird
, rapportd
が動き出しています。また、 WiFiAgent
も error ((null))
となっており、エラーが生じていないことがわかります。
つまり、bluetoothd
がデバイス接続をできていないところに原因がある のではないかと推察できます。
エラーの発生理由は Failed to encrypt the connection, the connection has timed out unexpectedly.
となっています。これがなぜ発生するかまでは追求できていませんが、ひとまず、bluetoothdによるデバイス接続の挙動がおかしい(完了してくれていない)ということがわかります。
✅(改善される)bluetoothd の再起動
上記のログ情報から、bluetoothd が原因の様に思えますので、これをリスタートしてみることにしました。
bluetoothdは launchctl kikstart -K
コマンドで再起動することができます。
sudo launchctl kickstart -k system/com.apple.bluetoothd
これにより、スリープ後のテザリングがうまくいかない場合も、コマンド1行うつだけで改善できるようになりました。
🤔 接続エラーのトリガーは...?
Bluetooth 関係のトラブルということで、思い当たることは、私が bluesnooze をインストールして使っていることです。
まさにこの記事の通り、マルチポイント接続しているヘッドホンを起動したり操作したりすると、頻繁にスリープしているMacが起動するのが嫌で、その対策として入れていました。
bluesnooze は、Macがスリープになった際にBluetoothをオフにし、スリープ解除されたときにBluetoothをオンにするはずですが、このオンにする中での過程や、オンになった時のiPhoneとの再ペアリング(ボンディング?)が不完全になってしまうのではないかと思っています。
📖 まとめ
スリープ後のテザリング再接続におけるトラブルについて、色々試した上で、ログを見て怪しいところを見つけ、改善方法(bluetoothdの再起動)で改善されることを確認しました。
なにかトラブルがあった際、とりあえず思いついた案を試してみることも多く、またそれで解決すればそれはそれで喜ばしいのですが、ログを見て、具体的なトラブルの姿や解決方法のあたりをつける ことが大事だなと改めて認識しました。