macOSXのスリープ後にテザリングが再接続できない時はbluetoothdをkickstart -kする

この記事は、[ゆるWeb勉強会@札幌 Advent Calendar 2022](https://adventar.org/calendars/7513)の23日目です。今回も開発環境（？）の話です。

https://adventar.org/calendars/7513

## 要約

macOS Monterey (12.6.2）を**スリープから復帰させた後に、直前までテザリングしていたiPhoneでもう一度テザリングしようと試みたところ、接続エラーが発生する**トラブルに見舞われました。

![fig01.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/8064/00714f12-cfa5-2e6b-f3fc-a61b63fd74fe.png)
![fig02.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/8064/a0021cab-5bbb-1f09-6a15-9bbf5f78ea3a.png)
![fig03.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/8064/b4f58faa-dfff-c650-3c9f-3365c9609135.png)


再接続も繰り返すもうまくいかず、毎回再現するようになってしまったのでログを含めて調査したところ、**bluetoothd を再起動すれば解決する** ことがわかりました。

```sh
 sudo launchctl kickstart -k system/com.apple.bluetoothd
```

**トラブル時はログを見るのが大事** ですね。

なお、このトラブルはおそらく私が [bluesnooze](https://github.com/odlp/bluesnooze) を使っているからなので、多くの方は同様の問題に陥らないのではと思いますが、色々調べた・試した内容を備忘録として残しておきます。

## やってみたこと

### ✅（改善される）macOSX or iPhoneの再起動

解決するが、毎回再起動の時間を待つのはいささか面倒なので、他の方法を探したいなとなりました。

### 🚫（改善されない）ネットワークインターフェースの再起動

接続エラーの時、ネットワークインターフェースは inactive になっていました。

![ifconfig en0](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/8064/ee834d84-f2d6-9805-8195-7f8369092b3c.png)

なので、ネットワークインターフェースを再起動してみたらどうでしょうか。

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でログを追いながら、再接続できない時と、うまく再接続できる時（再起動などをした場合）のログを比較すると、以下の様な違いがあることがわかりました。

![fig05.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/8064/c3e69533-972e-a229-ae3e-e5d786316680.png)


**接続エラーが発生する際のログ**: 分かりやすい様に一部改行しています。

```
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` コマンドで再起動することができます。

```sh
 sudo launchctl kickstart -k system/com.apple.bluetoothd
```

これにより、スリープ後のテザリングがうまくいかない場合も、コマンド1行うつだけで改善できるようになりました。

## 🤔 接続エラーのトリガーは...？

Bluetooth 関係のトラブルということで、思い当たることは、私が [bluesnooze](https://github.com/odlp/bluesnooze) をインストールして使っていることです。

https://applech2.com/archives/20210816-bluesnooze-prevents-sleeping-mac-from-connecting-to-bluetooth-accessories.html

まさにこの記事の通り、マルチポイント接続しているヘッドホンを起動したり操作したりすると、頻繁にスリープしているMacが起動するのが嫌で、その対策として入れていました。

bluesnooze は、Macがスリープになった際にBluetoothをオフにし、スリープ解除されたときにBluetoothをオンにするはずですが、このオンにする中での過程や、オンになった時のiPhoneとの再ペアリング（[ボンディング？](https://support.apple.com/ja-jp/guide/security/sec82597d97e/web)）が不完全になってしまうのではないかと思っています。

## 📖 まとめ

スリープ後のテザリング再接続におけるトラブルについて、色々試した上で、ログを見て怪しいところを見つけ、改善方法（bluetoothdの再起動）で改善されることを確認しました。

なにかトラブルがあった際、とりあえず思いついた案を試してみることも多く、またそれで解決すればそれはそれで喜ばしいのですが、**ログを見て、具体的なトラブルの姿や解決方法のあたりをつける** ことが大事だなと改めて認識しました。