概要

記事一覧はこちらです。

Spring Boot + Spring Integration でいろいろ試してみる ( その３０ )( Docker Compose でサーバを構築する、SMTP over SSL＋POP over SSLサーバ編 ) で POP over SSL を試すと全ての Docker コンテナとの通信が出来なくなると書きましたが、何か対応方法がないか調べてみましたので、そのメモ書きです。結局解決はできませんでしたが。。。

参照したサイト・書籍

Windows Defenderのリアルタイム保護を無効化/有効化する
https://news.mynavi.jp/article/win10tips-251/
Configure and troubleshoot the Docker daemon
https://docs.docker.com/config/daemon/
moby/vpnkit
https://github.com/moby/vpnkit
Docker for WindowsのMobyLinuxVMに接続する方法
https://qiita.com/gentaro/items/cf666259cb6baf2eb8db
How do I request a file but not save it with Wget? [closed]
https://stackoverflow.com/questions/9691367/how-do-i-request-a-file-but-not-save-it-with-wget
【Go】マルチプレクサってなんやねん
https://qiita.com/huji0327/items/c85affaf5b9dbf84c11e
docker stats
https://docs.docker.com/engine/reference/commandline/stats/
「top」は時代遅れ！？これからは「htop」を使おう！
https://linuxfan.info/htop
htop - an interactive process viewer for Unix
https://hisham.hm/htop/

Windows Defender のリアルタイム保護が原因ではないようだ
Docker 関連のログは C:\Users\<ユーザ名>\AppData\Local\Docker\log.txt に出力される
VpnKit とは？
MobyLinuxVM に接続して通信状況を確認する
docker stats コマンドでコンテナ毎のリソース使用量をリアルタイムで見られる
htop をインストールしてコンテナ内のプロセスの状況を見てみる

手順

Windows Defender のリアルタイム保護が原因ではないようだ

Windows Defenderのリアルタイム保護を無効化/有効化するという記事を見つけて、全てのコンテナへの通信ができなくなるのは POP over SSL の時だけなので、もしかするとこれが原因か？。。。と試してみましたが、関係ありませんでした。PowerShell を管理者として実行した後、Set-MpPreference -DisableRealtimeMonitoring 1 で無効にしてから試してみましたが、再発します。

Docker 関連のログは `C:\Users\<ユーザ名>\AppData\Local\Docker\log.txt` に出力される

Configure and troubleshoot the Docker daemon の「Read the logs」に Windows の場合には AppData\Local にあると書かれていたので、調べてみたところ C:\Users\<ユーザ名>\AppData\Local\Docker\log.txt に出力されていました。

[03:43:24.374][Moby           ][Info   ] [   67.770300] IPv6: ADDRCONF(NETDEV_CHANGE): vethd4a2099: link becomes ready
[03:43:24.412][Moby           ][Info   ] [   67.804819] br-e83b99f00770: port 1(vethd4a2099) entered blocking state
[03:43:24.445][Moby           ][Info   ] [   67.843327] br-e83b99f00770: port 1(vethd4a2099) entered forwarding state
[03:43:24.517][Moby           ][Info   ] [   67.890008] IPv6: ADDRCONF(NETDEV_CHANGE): veth753c8c1: link becomes ready
[03:43:24.547][Moby           ][Info   ] [   67.948086] br-e83b99f00770: port 3(veth753c8c1) entered blocking state
[03:43:24.588][Moby           ][Info   ] [   67.979328] br-e83b99f00770: port 3(veth753c8c1) entered forwarding state
[03:43:24.753][ApiProxy       ][Info   ] time="2018-12-27T03:43:24+09:00" msg="proxy << POST /v1.25/containers/9a96b7e2b06c03c8153949f25f93a05cd3e2848241fede2e756d6ee077b5b887/start (3.3064587s)\n"
[03:43:24.773][ApiProxy       ][Info   ] time="2018-12-27T03:43:24+09:00" msg="proxy << POST /v1.25/containers/4133e614b7baa7404d7d2459443c5e83d200e47ac265c838720f1c2a64b6bcd2/start (2.709457s)\n"
[03:46:56.439][VpnKit         ][Info   ] vpnkit.exe: Connected Ethernet interface f6:16:36:bc:f9:c6

[03:46:56.439][VpnKit         ][Info   ] vpnkit.exe: UDP interface connected on 192.168.65.1

[03:47:07.337][VpnKit         ][Error  ] vpnkit.exe: Socket.Stream: caught 既存��E接続��EリモーチEホストに強制皁E��刁E��されました、E

[03:47:22.580][VpnKit         ][Error  ] vpnkit.exe: Socket.Stream: caught 既存��E接続��EリモーチEホストに強制皁E��刁E��されました、E

[03:48:08.141][VpnKit         ][Error  ] vpnkit.exe: Socket.Stream: caught 既存��E接続��EリモーチEホストに強制皁E��刁E��されました、E

VpnKit の Error が出力されている（UTF-8 で表示させたにも関わらず文字化けしていますが。。。）。そもそも VpnKit って何？
その前のログを見ていると IPv6: ADDRCONF(NETDEV_CHANGE): veth753c8c1: link becomes ready というログが出ている。コンテナの方でも IPv4 で通信していると思っていたが、IPv6 を使っている？

VpnKit とは？

https://twitter.com/Docker/status/800760722716299264 には VPNKit is a set of tools and services for helping HyperKit VMs interoperate w/ host VPN configurations. と書かれていました。Port-forwarding を読むと、ホストからコンテナへのポートフォワードを行ってくれるのも vpnkit のようです。

コンテナと通信できなくなる問題が発生した時も vpnkit は Error ログを出力していて動いているようなので、Plumbing inside Docker for Windows の図を見た感じだと Hyper-V か Docker の MobyLinuxVM の問題なのでしょうか？

MobyLinuxVM に接続して通信状況を確認する

MobyLinuxVM に入って状況を確認できないのか調べてみたところ、Docker for WindowsのMobyLinuxVMに接続する方法という記事を見つけました。

この手順で MobyLinuxVM に接続して見てみると wget コマンドが使えることが分かったので、通信不可になる前の状態の時に以下２つの URL へアクセスしてみると、どちらも問題なくアクセスできました。

wget -O- ip6-localhost:8888/rainloop/v/1.12.1/static/apple-touch-icon.png（コンテナ内の URL）
wget -O- https://www.gstatic.com/images/branding/googlemic/2x/googlemic_color_24dp.png（インターネット側の URL）

f:id:ksby:20181228124844p:plain

通信不可になってから再度試してみても、どちらも問題なくアクセスできました。

f:id:ksby:20181228125846p:plain

vpnkit.exe: Socket.Stream: caught 既存��E接続��EリモーチEホストに強制皁E��刁E��されました、E というログと、今回確認した結果を合わせると、

vpnkit.exe は起動時に MobyLinuxVM と Socket.Stream を接続する（接続したままにする）。
POP over SSL で接続不可になった時には、この Socket.Stream の接続が強制切断されている。
vpnkit.exe - MobyLinuxVM 間の Socket.Stream が切れているため、PC からコンテナへの通信が全て失敗する。

という状況のような気がします。仮にこの推測が正しいとすると、接続・切断を繰り返す SSL 通信を PC - コンテナ間で実施すると POP over SSL の時と同様に、全てのコンテナにアクセスできなくなる状況が発生するということでしょうか？

後から気づきましたが、MobyLinuxVM に接続できると /var/log の下に出力されている Docker のログファイルが見れました。

f:id:ksby:20181229133458p:plain

vpnkit が port forward している時のログと思われるファイルがちょうど vpnkit-forward.log という名前であったので、tail -f vpnkit-forwarder.log で問題発生時のログを見てみると Multiplexer main loop failed with Unknown channel id: 10 というログが出力されていました。

f:id:ksby:20181229140614p:plain

Multiplexer って何？。。。と思って調べてみると、【Go】マルチプレクサってなんやねんという記事を見つけました。vpnkit は Go ではなく OCaml で実装されていますが、概念的には同じようなもののはず。中でエラーが出ていることは分かりましたが、これ以上はどうしようもないかな。。。

もう１点。vpnkit.exe は PC 上で実行されていますが（Windows のタスクマネージャで動作しているのが確認できます）、

f:id:ksby:20181229174934p:plain

なぜ MobyLinuxVM 上でログが出るのだろう？と思って MobyLinuxVM で ps -ef | grep "vpnkit" で見てみたらポートフォーワードの設定毎に /usr/bin/vpnkit-expose-port が実行されていました。そんな仕組みだったとは。。。

f:id:ksby:20181229175600p:plain

問題発生後に ps -ef | grep "vpnkit" を実行してみましたが、出力される結果は変わりませんでした。/usr/bin/vpnkit-expose-port が落ちている訳ではないようです。また docker-compose down コマンドを実行すると /usr/bin/vpnkit-expose-port のプロセスは全てなくなりました。