tar で固める際に進捗を知る

こんにちは。masm11 です。

大きなディレクトリを tar で .tar.gz に固めることってありますか? 時々ありますよね。 最近は zip の方が多いのでしょうか? 私は tar を使っています。例えば以下のようにします。

tar zcf /bak/backup.tar.gz dir

しかし、大きなディレクトリを .tar.gz にすると時間がかかるので、進捗を知りたくなります。

今回はその方法を紹介したいと思います。

まずは普通に

tar に v を付けると、ファイル名を出力してくれます。

tar zcvf /bak/backup.tar.gz dir

ですが、この場合、ファイル名とエラーメッセージが両方端末に出力されるので、 エラーの確認が難しいです。

ファイル名を別ファイルに保存する

tar zcvf /bak/backup.tar.gz dir > log

こうすると、 log にファイル名が出力されていきます。エラーメッセージは端末に出力されます。

log は別端末で

tail -f log

とでもしておけば、確認できますね。

別端末に送り込む

ファイルに出力するのが嫌な場合、別端末に直接送り込むこともできます。

端末を2枚開いて、それぞれで

tty

というコマンドを実行します。端末の ID のようなものが出力されます。 ここでは、/dev/pts/0, /dev/pts/1 だとします。

/dev/pts/0

tar zcvf /bak/backup.tar.gz dir > /dev/pts/1

と実行すると、/dev/pts/1 の方にファイル名が出力されます。エラーメッセージは /dev/pts/0 の方に出力されます。

各ファイルのサイズも見たい場合

例えば

tar ztvf /bak/backup.tar.gz

を実行すると、backup.tar.gz の中にあるファイルの、ファイル名やサイズ等が出力されます。

固めている間に見たければ、別端末でこのコマンドを何度も実行すれば、そのたびにファイル名やサイズ等が出力されますが、 backup.tar.gz は大きいので、一度見た前の方の情報は不要です。できれば、tar zcvf の時のように順次出力して欲しいです。

そこで、tail -f を使う方法を考えました。

/dev/pts/1:

echo -n '' > /bak/backup.tar.gz
tail -f /bak/backup.tar.gz | tar ztvf -

/dev/pts/0:

tar zcf /bak/backup.tar.gz dir

tar zcf で backup.tar.gz を作っていきます。backup.tar.gz が大きくなったら大きくなった部分だけ tail -f で読み取り、 tar ztvf でファイル名やサイズ等を出力しています。

ただ注意として、既に大きくなった backup.tar.gz がある場合、tail -f は後ろの方しか出力してくれないので、zcat が 「ファイル形式がおかしい」とエラーを吐きます。なので、tail -f は先に実行しておく必要があるのですが、 ファイルがなければ tail -f がエラーになりますので、最初に echo -n で空ファイルを作っています。 touch でもファイルを作れますが、もしファイルがあった場合、タイムスタンプが変わるだけになってしまうので、 明示的に空ファイルにするために echo -n にしています。

結果は以下のような感じになります。

f:id:masm11:20200715123320p:plain
実行中画面サンプル

まとめ

tar zcf で大きなディレクトリを固めている際に進捗を知る方法を紹介しました。

いろいろな方法がありますね。UNIX/Linux ではいろいろな方法があって、好みの方法を選べるところが私は好きです。

ではまた!

dovecot が起動してない?

https://upload.wikimedia.org/wikipedia/commons/3/37/Dovecot-logo.png

どうも id:kizashi1122 です。

弊社が開発・運営している Re:lation というサービスの中のサーバではないのですが、とある用途で IMAP のサーバをAWSのEC2上に立てていました。ソフトウェアとしては dovecot を使っています。

Dovecot

さて、社内の利用者より「つながらないんですけど」と連絡がありました。

んなアホなと思い、みてみると確かに IMAP の接続に失敗する。認証に失敗ではなく接続に失敗する。

$ ps -ef | grep dovecot

をすると、プロセスがあがってません。 ps auxw を使ってない理由は特にないありません。昔 Solaris を使っていた手癖がまだ残ってるだけです・・・。

それはさておき。

上がってないなら上げればよいということで起動させようとしました。

[root@ip-172-31-XX-XX conf.d]# /etc/init.d/dovecot start
Starting Dovecot Imap: Error: service(pop3-login): listen(*, 995) failed: Address already in use
Error: service(imap-login): listen(*, 143) failed: Address already in use
Error: service(imap-login): listen(*, 993) failed: Address already in use
Fatal: Failed to start listeners
                                                           [FAILED]
[root@ip-172-31-XX-XX conf.d]#

誰かがポートを使ってる? んなアホな。

lsof で確かめます。

[root@ip-172-31-XX-XX conf.d]# /usr/sbin/lsof -i :993
[root@ip-172-31-XX-XX conf.d]# /usr/sbin/lsof -i :995
[root@ip-172-31-XX-XX conf.d]# /usr/sbin/lsof -i :143

ないんかい。

念の為、 netstat -tulpn でもみてみますが同ポートは誰もLISTENしてません。

困った。

困ったときの Google 先生。 以下のサイトがみつかりました。日付も近い。

stackoverflow.com

Hi it looks like you are using AWS as I am. I recently updated via Yum as well. I noticed that a new package named 'portreserve' was also installed. I killed that process, left the /etc/dovecot/dovecot.conf as it was before and then started Dovecot successfully. I was also immediately able to reconnect my mail clients connection. I hope that helps you.

I also restarted the portreserve program since it seems useful to limit port access.

まとめると、「最近 yum でアップデートしたら portreserve なるパッケージがインストールされてた。このプロセスを kill して dovecot を起動したらうまくいった」とのこと。

確かに、最近 yum でセキュリティアップデートがあったので yum update -y したばかりでした。その後再起動して放置してました。まさか dovecot が立ち上がってないとは思わず・・・。

実際に、このとおりにすると無事 dovecot が再起動しました。

ただ次にOSを再起動した際に同じことが起こるのはイヤです。

/etc/portreserve/ というディレクトリに dovecot というファイルがあります。

中身は

imap/tcp
imaps/tcp
pop3/tcp
pop3s/tcp
sieve/tcp

というような感じ。もうこいつが原因だろうということでこのファイルは削除しました。

ところで、この portreserve というサービスは何者なんでしょう? その名の通り、dovecot のために上記ポートを予約しておいてくれたのなら、なんで dovecot が立ち上がらなかったんだ?

謎が多いです。

今後は簡単に確認できるように、簡単な Perl スクリプトを作りました。

#!/usr/bin/env perl

use v5.16;
use Mail::IMAPClient;

my $imap_host = $ARGV[0] or die $!;
my $user      = $ARGV[1] or die $!;
my $pass      = $ARGV[2] or die $!;

my $imap = Mail::IMAPClient->new(
    Server   => $imap_host,
    User     => $user,
    Password => $pass,
    Ssl      => 0,
    Uid      => 1,
);

if ($imap) {
    say "AUTH OK";
} else {
    say "AUTH NG";
}

割り算の余りは?

こんにちは、masm11 です。

突然ですが、今回は、負の整数を正の整数で割った時の余りは 0 以上なのか 0 以下なのか、 という話を書きたいと思います。

具体的には、-22 % 3 はいくつなのか、というお話です。

実は、言語によって違うのです…

2 になるものたち

Ruby

Ruby は余りが 2 になります。

仕様は以下のページにあります。

https://docs.ruby-lang.org/ja/latest/method/Numeric/i/modulo.html

また、以下のページを見ると、Ruby 1.8.7 の時には既に明確に定義されていたようですね。

https://docs.ruby-lang.org/ja/1.8.7/class/Numeric.html#I_MODULO

実際に試してみました。

luna:~ % irb
irb(main):001:0> -22 % 3
=> 2
irb(main):002:0> 

Python

Python 3 は、以下の表の下の注釈 1. に記載がありました。

https://docs.python.org/ja/3/library/stdtypes.html#typesnumeric

結果(商)が負の無限大の方向に丸められるということは、余りは 0 以上です。

Python 2.7 でも、以下のページの表の下の注釈 1. に同様の記載がありました。

https://docs.python.org/ja/2.7/library/stdtypes.html#numeric-types-int-float-long-complex

Ruby と同様に実際に試してみました。

luna:~ % python
Python 3.8.2 (default, Apr  8 2020, 14:31:25) 
[GCC 9.3.0] on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> -22 % 3
2
>>>

-1 になるものたち

Java

Java では余りが -1 になります。

以下のページの floorDiv メソッドに説明がありました。

https://docs.oracle.com/javase/jp/8/docs/api/java/lang/Math.html#floorDiv-int-int-

/ で普通に割り算すると、0 に向かって丸められるようです。 ということは余りは -1 以下ですね。

そして floorDiv メソッドを使った場合は Ruby や Python と同じ丸め方になるようです。従って floorMod メソッドを使うと余りは 2 ですね。 更に、このメソッドには「導入されたバージョン: 1.8」と記載があり、Java 8 以降にしかないようです。

Java 7 については、以下に記載がありました。

https://docs.oracle.com/javase/specs/jls/se7/html/jls-15.html#jls-15.17.2

Integer division rounds toward 0.

やはり 0 に向かって丸めていたようです。

実際に試してみました。

luna:~ % java -version
openjdk version "1.8.0_242"
OpenJDK Runtime Environment (build 1.8.0_242-b08)
OpenJDK 64-Bit Server VM (build 25.242-b08, mixed mode)
luna:~ % cat test.java
class test {
    public static void main(String[] args) {
        System.out.println(-22 % 3);
        System.out.println(Math.floorMod(-22, 3));
    }
}
luna:~ % javac test.java       
luna:~ % java -classpath . test
-1
2
luna:~ % 

C99

以下に記載がありました。

https://kikakurui.com/x3/X3010-2003-01.html の 6.5.5

整数同士の除算の場合,/演算子の結果は,代数的な商から小数部を切り捨てた値とする(87)。

(87) には以下のように書いてあります。

これは, 0 方向への切捨てとも呼ぶ。

試してみました。

luna:~ % cat test.c
#include <stdio.h>

int main(void)
{
    printf("%d\n", -22 % 3);
    return 0;
}
luna:~ % cc test.c
luna:~ % ./a.out 
-1
luna:~ % 

処理系定義のもの

C89

C99 登場以前の C は C89 と呼ばれる規格に従っていました。 C89 の規格は簡単には手に入らなさそうなので、stackoverflow.com で見つけた情報 をご紹介します。

https://ja.stackoverflow.com/questions/12649/

C89 では処理系定義だったようです。つまり、結果がコンパイラや CPU に依存していた、ということです。

そんな処理系を持っていないので、残念ながら実際に試すことはできませんでした。

まとめ

C89 のコンパイラを使っていた時、ふと、余りが負であることに気付き、 私は衝撃を受けました。 それからずーっと気になっていて、今回ようやく各言語の状況をまとめることが できました。

昔はコスト的に 0 以下にすることを選んだ CPU が多く、C ではそれがそのまま 結果として現れているようです。しかし現在は CPU の処理能力も向上し、 少しくらい処理が増えても問題ないため、現代的な言語では 0 以上になっている のでしょう。

Java について言うと、私は Java は CPU 能力が潤沢にある環境で使うものだと 思っているので、そういう意味では意外な結果でした。

ではまた!

Gmail API(Google OAuth) 利用承認取得記 - 完結編

こんにちは。Tedです。

いよいよ今回でGmail API利用にかかるGoogleからの承認の取得記のラストです。

これまでの記事はこちら。

blog.ingage.jp

blog.ingage.jp

前回までで、Googleでの審査は一通り完了しました。いよいよセキュリティ評価です。

セキュリティ診断企業選び

https://support.google.com/cloud/answer/9110914 にあるように、この承認のためには第三者機関によるセキュリティ評価が必要(the system must undergo an independent (3P) security assessment)となります。また、この企業はどこでもよいわけではありません。Googleが指定する3社(すべて米国企業)から選ぶ必要があります。そしてその費用は、1万5千ドル〜7万5千ドル(約160万円~800万円)またはそれ以上かかります。

私たちの場合、このセキュリティ評価に入る時点で2019年の12月に入っていました。Google提示の3社の内、1社は多忙で年内は受け付け終了とありました。できれば年内に終わらせたかった*1ので、残りの2社から見積もりを取得することにしました。見積もりにあたり、Re:lationシステムの概要など必要な情報を提供します。これらのやりとりもすべて英語で行います。

2社からの回答は内容はほぼ同じ(当たり前)ながら、最初に出された費用は100万円ほど差がありました。ですが話を進めていく上でほとんど同じような額となりました。その見積額は約400万円でした。

両社ともしっかりした会社だったので、選ぶのには苦労しました。最終的には、回答が早く、納期も短かったB社に決めました。(とはいえ、ホリデーシーズンのためか結果的にテスト開始・終了は大幅にずれましたが)

セキュリティ評価で感じたこと

セキュリティ評価は下記のように進められました。

  1. キックオフミーティング(Web会議)

  2. B社によるセキュリティ評価

  3. 評価結果を元にレポートとその説明(Web会議)

  4. 指摘事項の修正とその内容の連絡

  5. B社での修正内容の確認

  6. 最終診断結果のレポートとその説明(Web会議)

B社から上がってきた診断レポートには、いくつか修正すべき点も指摘されていました。このレポートには私たちは大変満足しています。中には、Re:lationの仕様を十分に理解していないと指摘できないような内容も含まれていたためです。また、これまでの他社による診断では発見されなかったことも指摘に上がっていました。

はれてGoogleからの承認を得る

B社からの最終レポートをGoogleに送信すると、その翌日にはGoogleからの承認が下りました。すでに時は2020年2月も後半になっていました。Googleに最初に申請をしてから、実に4ヶ月以上・Googleとのやりとりは122回かかりました。

あらためて、今回の承認取得のポイントを下記に記したいと思います。

  • Google Cloud Consoleでの申請内容は別途保存しておきましょう。審査期間は限られており、期限を過ぎると再申請が必要となります。そのためもし再申請が必要となった際に重宝します。*2

  • 英語力は必要です。

  • 提出資料作成のため、英作文能力も必要です。

  • セキュリティ診断企業とのWeb会議のために英会話力も必要です。

  • セキュリティ診断にはまとまった費用が必要ですし、Googleが指定する企業を使う必要があります。予算の確保を前もってしておくとよいかと思います。

  • 基本的にGoogleは1-2日後には返事をくれます。

  • ただしそうでないときもあります。そんなときはフォローメールを送りましょう。*3

  • GoogleはWeb会議には応じません。コミュニケーションは必ずメールに限られます。英文での表現力・説明力はある程度必要になります。

122回のやりとりの中には、ここでは書き切れないほどのイベントが発生したのですが、ざっとこのようにまとめてみました。元々はこの3倍はあったボリュームをここまでまとめてくれたウチのCTOに感謝です。

もしこれがこれからGoogle OAuthを取得しようと思っている企業に有益となれば幸いです。質問があれば気軽にどうぞ。コメントやツイートなどwelcomeです。

*1:私たちの場合、このGoogleへの申請が12月31日で期限切れとなる予定でした。

*2:実際、私たちは期限切れで再申請する必要がありました。

*3:2-3度ほどGoogleからの返信が遅れたことがありましたが、フォローメールを送るとその翌日には返信がありました。

Gmail API(Google OAuth) 利用承認取得記 - 続

こんにちは。Tedです。

今回はGmail API(Google OAuth)の承認を得るにあたって行ったこと・起こったことについて書きたいと思います。

前回の記事はこちら

blog.ingage.jp

前回はGoogleへの申請までを書きました。今回は申請でどのようなことを行ったのか、Googleからはどのような指摘があったのかを詳しく書きたいと思います。

Googleに申請

申請の依頼自体は簡単です。 Google Developer ConsoleにてOAuth同意画面から依頼を行います。

f:id:TedWada:20200508144444p:plain

f:id:TedWada:20200508144514p:plain

このように認証を依頼するための申し込み画面は日本語で表示されていましたが、私たちが入力する文章はすべて英文で行いました。確認するのはGoogle本社(米国)であり、スムーズに審査を進めてもらうには英語で書くのがよいと思ったからです。(後述の通りこの予想は正解でした)

最初の一週間でやったこと

申請してその翌日からGoogleとのやりとりがはじまりました。流れとしては確認に際してGoogleから質問や依頼があり、それを元に私たちが回答・対応していくという流れです。Googleからの回答は素早く、こらちからのメール送信後1日から2日くらいで返信が届きます。

最初の一週間でのGoogleからの依頼とその対応は下記のようなものでした。

  • Googleサービス内のユーザデータの何を使うのか、そのためにGoogle APIの何を使うのか、なぜ使うのか、何に使うのかを文書にて回答。

  • アプリケーションが Google APIをどこで使っているかについて、デモ動画を作成。

  • Googleの審査員がアクセスできるRe:lationテスト環境の提供。

  • 外部サーバにはGoogleユーザデータは送信していない旨の説明。

  • デモ動画内のメッセージはすべて英語である必要があるとのことで、すべての日本語部分を英語に変更。*1 (当初説明テロップは英語にしていたが、Re:lation画面は日本語のままで収録していた)

  • デモ動画にてブラウザのURLバーは消さない。特にプロジェクト番号が表示されるOAuthサインインページが見えるように動画を再作成。

  • Google Cloud Console内のOAuth同意画面にて、不要なクライアントIDを削除。(開発の際に利用した不要なクライアントIDが入っていた)

  • デモ動画にて、申請している利用APIが使われるアクションが何なのかを明確にするため再収録。

申請時同様、すべてのやりとりは英語で行います。メールでのやりとりだけでなく、提供する文書もすべて英文で提出しました。

対応はなかなか終わらない

Googleによる審査は「案外しっかり見ている」と感じられるものでした。 最初の一週間以降もGoogleから下記のように指摘や質問があり、都度それらへの対応を進めました。

  • デモ画面でのアクション・説明の追加と再提出。(合計3回ほど)

  • Google OAuthにて利用するデータを明記する。

  • Googleサインインブランディングに沿った表記とする。(これは推奨であり、規定の通りとするとRe:lation内の他の設定と比較してデザインが破綻すると考えたので「やらない」と回答)

  • Re:lationにて使用するドメインはインゲージが所有していることをWebサイトにて明示する。(これはサービスサイトからログインできるページにて明示)

回答しても回答しても、Googleからは新たな指摘や質問が続きました。なかなか先が見えない中で私たちも大変でしたが、Googleも同様だったのではないかと思います。Googleからの返信の中には、すでにこちらから連絡済みのことを重複して聞いてくることも何度かあったくらいです。

Googleでの確認は終了。そして次は

上記の対応でおよそ1ヶ月が過ぎました。

Googleでの確認は一通り終わり、次のステップである第三者機関によるセキュリティ評価診断を受けるフェーズとなりました。

ここでもいくつかポイントがありました。 それについては次回に書きたいと思います。

*1:翻訳はGoogle翻訳によるウェブサイト翻訳を利用しました。

Gmail API(Google OAuth)利用承認取得記 - 思ったより大変でした

こんにちは。Tedです。

先日メール・LINE共有クラウドRe:lationにてGoogleからGmail API利用の承認を得ました。予想していたより大変であったので、備忘録的にここに記載しておこうと思います。

Google OAuth利用の声は高まっていた

Re:lationではメールの送受信にSMTP、POP3を利用します。Gmail(ここではG Suiteも併せて単に「Gmail」と書きます)ではSMTP、POP3をRe:lationなど外部メールクライアントにて利用するためには、Gmail設定にて「安全性の低いアプリを許可する」ことが必要でした。

f:id:TedWada:20200508140632p:plain

SMTP等を使うことを一方的に「安全性が低い」と決めつけられるのは気持ちのいいものではありません。ただGoogleとしてはID、Passwordを他のシステムで保存されるようなことは極力避けたいのでしょう。Google OAuthを使ってほしいという思惑でもあると思います。実際Re:lationでもGoogle OAuth対応は以前より取り組み予定として位置づけていました。

またGoogle OAuth対応までは、下記のようなお声をいただくこともありました。

f:id:TedWada:20200508140810p:plain https://twitter.com/juners/status/716261432908603392

対応の予定はしていたものの、他の案件との兼ね合いでこれまでリリースできていなかったことを申し訳ないなと感じていました。

SASL XOAUTH2対応が必要となった

いよいよRe:lationにてGoogle OAuth(SASL XOAUTH2)対応に着手できるようになった頃、奇しくもGoogleから「Turning off less secure app access to G Suite accounts(「安全性の低いアプリ」設定を廃止するよ)との通達がありました。

G Suite Updates Blog: Turning off less secure app access to G Suite accounts

この通達では2020年6月以降「安全性の低いアプリ(LSAs)」の設定に制限を実施すること、2021年2月にはこのLSAs許可設定ができなくなることが書かれていました。*1 つまりRe:lationでのGoogle OAuth対応の期日が決められたことになります。私たちは早速開発を進めました。

開発・そしてリリース

この対応にはGmailユーザのみGmail REST APIを使う手もありましたが、他のメールサービス同様にSMTPプロトコルを使う(スコープは https://mail.google.com/)こととしました。

開発およびテストはスムーズに進んだと思います。他の案件も並行して進める中で約4週間で完了しました。

ingage.co.jp

Google OAuthできない!なぜ??

この機能、リリース当日は問題ありませんでしたが、翌日になると利用者より「Google OAuthでのログインができない」との声が寄せられるようになりました。

f:id:TedWada:20200508142327p:plain
Google OAuthできずエラーになる

理由は明快でした。OAuth可能ユーザ数の上限に達したためにそれ以降のログインが許可されなくなっていたのでした。

Google OAuthを利用可能なユーザは、最初100までと決められています。

f:id:TedWada:20200508142653p:plain

このことは理解していましたが、正式に機能をリリースしてGoogleに「連絡」さえすればこの上限は外されると勝手に思い込んでしまっていました。けれどもそれは間違いで、この制限を取り払うためにはGoogleに「審査」を依頼する必要があったのでした。

Unverified apps - Google Cloud Platform Console Help

GoogleにOAuth利用を申請

Gmail APIスコープは制限されたスコープとなっています。そのため、このスコープをOAuthにて設定するにはGoogleによる以下の検証(認証)が必要です。

  • Google’s API Services User Data Policy に従っているか
  • Additional Requirements for Specific Scopes に従っているか

また加えて、上記がGoogleにて確認された後、第三者によるセキュリティアセスメントも必要となっています。

これらはかなり本格的なものであり、承認取得までには私たちが当初予測していたよりずっと長い時間と対応が必要でした。

次回は、GoogleからのGmail API承認取得までの道のりについて書きたいと思います。

*1:注:2020年5月8日時点では、Googleによるこれらの予定は急遽延期されることとなっています。おそらく新型コロナの影響かと思われます

macOS Catalina の NFS 問題を解決する

こんにちは、masm11 です。

弊社では、macOS 上の Vagrant 環境内から、macOS のディレクトリを NFS で mount して、 開発しています。 仮想マシンとしては VirtualBox を使用しています。 この度、私に貸与された mac の macOS を Catalina に上げた ところ、NFS mount ができない、という症状が発生しました。

今回はこの症状を解決するまでをご紹介します。

なお、macOS は Catalina 10.15.4、Vagrant は 2.2.7 です。

症状

vagrant up すると、途中まではうまく処理が進むのですが、 NFS mount するところで、以下のように失敗します。

==> default: Exporting NFS shared folders...
==> default: Preparing to edit /etc/exports. Administrator privileges will be required...
==> default: Mounting NFS shared folders...
The following SSH command responded with a non-zero exit status.
Vagrant assumes that this means the command failed!

mount -o vers=3,udp 192.168.33.1:/System/Volumes/Data/Users/masm/proj/ra/share /vagrant

Stdout from the command:



Stderr from the command:

mount.nfs: requested NFS version or transport protocol is not supported

そして、少し経ってから vagrant ssh でログインし、手動で

sudo mount -o vers=3,udp 192.168.33.1:/System/Volumes/Data/Users/masm/proj/ra/share /vagrant

を実行すると、なんと成功します。

おそらく、どこかで何かがタイムアウトしているのでしょう。

情報を漁ってみる

世の中で既にたくさん使われているはずの Catalina です。そして Vagrant もです。 情報がないはずがありません。

ぐぐってみると、たくさんの情報が見つかりました。一番多かったのがこれです。

  • /etc/exports に書く macOS 側 path は /System/Volumes/Data/... になっていること。

    しかし、最新の Vagrant なら既にそうなっています。上に書いたエラーメッセージでもそうなっていますね。

また、Vagrant の issue をいくつか見たところ、以下の情報が得られました。

  • 既知のディレクトリ (~/Documents みたいな) を export しないこと。

    既知のディレクトリを export する場合は /sbin/nfsd にフルディスクアクセス権限を与える必要があるそうです。

    私の場合は独自のディレクトリですので、該当しません。そもそも権限が問題なら、時間が経ったら 成功する、などということはないはずです。

  • macOS 側 /etc/hostslocalhost をちゃんと書いておくこと。

    普通は書いてあると思います。私も書いてありました。

    ただし、私の場合、showmount -e localhost が何も返さず黙ったまま、という症状もあり、 それは ::1localhost にしてあったのが原因でした。::1 を削除したところ、 この症状はおさまりました。

  • Vagrantfile 内 synced_folder は1つだけにすること。

    複数書くと、/etc/exports の1行に複数個のディレクトリが並ぶ場合があって、その場合に問題が起きていたようです。

    このコメントに例付きで書いてあります。

    最新の Vagrant では大丈夫かもしれませんが、追い切れていません。

    私の場合、synced_folder は1つだけでした。

以上が、情報を漁った結果です。

さらに症状は続く…

しかし、これらの情報では解決に至りませんでした。

仕方ありません、独自の調査を試みてみます。

NFS をやめる

代わりに VirtualBox の sync folder を使うという手があります。

しかし sync folder は遅いのです。NFS が解決しなければ sync folder を 使うという手も考えましたが、遅くて開発に支障が出そうだったので、解決しない 場合は解決しないまま使うことにしました。問題なのは mount する時だけ ですから。

rpcinfo してみる

NFS で問題が起きたら、とりあえず rpcinfo だと思っています。

rpcinfo とは何でしょうか? 使う前に少し説明してみます。

普通、サービスにはポート番号が割り当てられていますね。smtp であれば 25番、 http であれば 80番です。しかし、ポート番号は 16bit であり、1~65535 しかなく、 しかもその中はざっくりと範囲に用途が決まっています。well-known ポートであったり、 エフェメラルポートであったり、NAT に使うものであったり、よくわからないサービスが 独自に割り当てて使ってしまうものであったりします。つまり、65535個って結構たくさん あるように見えて、割り当てられる番号はその極一部なのです。有限なのです。 使うかどうかも判らないようなサービスにポート番号を固定で割り当てたくはないのです。

すると、当然、「じゃぁ動的に割り当てよっか?」という発想が生まれます。つまり、 もっと広い空間の「プログラム番号」「プログラム名」を用意し、使われていないポート番号 から動的に割り当て、「プログラム番号」→「ポート番号」の表を管理しておくのです。 こういった機構を portmap などと呼んでいます。

rpcinfo -p 192.168.33.1 を実行すると、192.168.33.1 のマシンの中のその表を管理 しているプロセスから、その一覧を取得することができます。

試してみましょう。

yuukinombp:~ % rpcinfo -p 192.168.33.1 | grep nfs
    100003    2   udp   2049  nfs
    100003    3   udp   2049  nfs
    100003    2   tcp   2049  nfs
    100003    3   tcp   2049  nfs

100003 はプログラム番号、2 や 3 はプログラムのバージョン、 udp や tcp は使用するプロトコル、 2049 はポート番号、nfs はプログラム名です。つまり、nfs の vers=2 の UDP 版は ポート 2049 を使用する、と読みます。

192.168.33.1 の nfs に UDP でアクセスしたいクライアントは、 一旦 192.168.33.1 の portmap にリクエストを投げ、 nfs の vers=2 の UDP が 2049 であることがわかったら、 改めて 2049/udp に nfs のリクエストを投げる、 ということになります。

ただし、この仕組みは広くいろんなサービスに使われているわけではありません。 結局、NFS や NIS くらいでしか使われなかったように記憶しています。

さて、話を戻します。

NFS mount できる時とできない時で差がありました。できない時には mountd がありません。例をお見せします。

yuukinombp:~ % rpcinfo -p 192.168.33.1 | grep -E 'nfs|mountd'
    100003    2   udp   2049  nfs
    100003    3   udp   2049  nfs
    100003    2   tcp   2049  nfs
    100003    3   tcp   2049  nfs
yuukinombp:~ % rpcinfo -p 192.168.33.1 | grep -E 'nfs|mountd'
    100003    2   udp   2049  nfs
    100003    3   udp   2049  nfs
    100003    2   tcp   2049  nfs
    100003    3   tcp   2049  nfs
    100005    1   udp    632  mountd
    100005    3   udp    632  mountd
    100005    1   tcp    991  mountd
    100005    3   tcp    991  mountd
yuukinombp:~ %

上側が mount できない時、下側が mount できる時です。

たまたまかもしれません。もう少しタイミングをしっかり確認してみましょう。

macOS 側で以下を実行します。

while :; do rpcinfo -p 192.168.33.1 | grep -E 'nfs|mountd'; sleep 1; done

別の端末で、vagrant ssh して以下を実行します。

while ! sudo mount -o vers=3,udp 192.168.33.1:/System/Volumes/Data/Users/masm/proj/ra/share /vagrant; do sleep 1; done

ようするに、rpcinfo を1秒おきに実行しながら、mount も1秒おきにやってみる、ということです。

少し時間が経つと、両方同時に変化がありました。 rpcinfo は mountd を出力するようになりましたし、mount も完了しました。 タイミング的には1秒未満の差です。関連してそう、と思って良いでしょう。

私もどのプログラムがどういった役割をしているのか、それほど把握しているわけでは ないのですが、mountd がいなければ mount はできないのでしょう。

しかし、何故そんなことになるのかはさっぱり原因がつかめません。

log を見る

困って更にぐぐっていたある日、syslog を見る方法を見つけました。

その名も log コマンド。

log stream --style=syslog

とすれば、syslog っぽく整形されたログがどんどんリアルタイムで出力されていきます。

これです! これが欲しかったんです! これさえあれば…

nfs に関するメッセージを探してみたところ、ありました!

2020-04-18 01:37:34.795213+0900  localhost nfsd[7277]: couldn't register NFS/TCP service.

これですね。

couldn't register は、portmap の表に登録できない、という意味なのでしょう、おそらく。 そして、NFS/TCP と書いてありますね。ならば、TCP を無効にしてみましょう。

/etc/nfs.conf に以下のように書きます。

nfs.server.tcp = 0

これで vagrant up しなおします。

==> default: Exporting NFS shared folders...
==> default: Preparing to edit /etc/exports. Administrator privileges will be required...
Password:
==> default: Mounting NFS shared folders...
==> default: Mounting shared folders...
    default: /tmp/vagrant-chef/783542ad0dccc700ff72bcae0833b125/cookbooks => /Users/masm/proj/ra/cookbooks
==> default: Machine already provisioned. Run `vagrant provision` or use the `--provision`
==> default: flag to force provisioning. Provisioners marked to run always will still run.

いけました! めでたく mount できました。

根本原因 (何故 TCP 版が登録できないのか) はわかりませんが、これでひとまず解決です。

考慮点

これでは TCP 版 NFS が使えません。が、Vagrant が UDP を指定しちゃっているので、 TCP を無効にしても影響はないでしょう。

ただ、今後、docker を使うなどで TCP での NFS を使いたくなった場合には、改めて 困るかもしれません。

まとめ

NFS トラブルの解決策が見つからなかったため、自力で解決してしまいました。 ただ、ぐぐって情報を集めても、同様の症状はほとんど見当たりませんし、 たまにあっても解決していませんでした。少数派なのでしょうね。

それにしても、最近、どの OS も syslog をバイナリ化してしまうので、困ります。 テキストファイルなら、テキストファイルを扱えるコマンドは無数にありますから、 好みの方法で使えます。しかしバイナリ化されていると、専用コマンドの使い方を 覚えて、一旦テキスト化してやる必要があります。 テキストでいいじゃん… とは思うのですが、バイナリにもそれなりのメリットが あるのでしょうね。

後日談

と、ここまで書ききった後で、後日談が生まれました。

社内で「ESET をバージョンアップしたら NFS mount できなくなった!」 「NFS mount できない時は ESET ファイアウォールを一旦無効にしてます!」 という声があり、どうやら ESET が影響しているということが判りました。

パーソナルファイアウォールのログを確認したところ、ターゲットのポートが 111 なのは予想通りでしたが、ソースの IP アドレスが :: となっていました。 IPv6 です。 しかし :: をルールの IP/IPv6アドレスに入力してもルールが作成できません。 代わりに ::0 と入力すると作成できました。

まとめると、以下のルールを作成することで、NFS mount できるようになりました。

  • 名前: RPC/NFS 等、適当なもの
  • すべてのアプリケーション: ON
  • アクション: 許可
  • 方向: 両方
  • プロトコル: TCP
  • ポート: ローカル
  • ローカルポート: 111
  • 宛先: IPアドレス
  • IP/IPv6 アドレス: ::0

私の ESET は ESET Cyber Security Pro 6.8.300.0 です。

nfs.conf に手を加えるか、パーソナルファイアウォールに設定するか、 どちらかお好みの方法で良いと思います。

ではまた!