Ctrl-T一押しでMinitestの失敗を即座に確認する方法

小さな機能を実装し終えて、コミット前に統合テストの一式を回そうとします。画面にドットが並んでいくのをじっと待っていると……

......FF....

:(

テストの実行が終わるまでにはまだ数分かかります。しかし、ここで実行を中断してしまうと、どのテストが失敗したのかまったく分かりません。

失敗内容を確認するために、本当に最後まで待つしかないのでしょうか?

Ctrl-Tが救ってくれる!

Macを使っているなら、テストの失敗を早めに確認する方法があります。

テストの実行中に Ctrl-T を押してみてください。

すると、現在どのテストケースが実行されているのか、そしてそれがどれくらいの時間動き続けているのかが表示されます。さらに、その時点までに失敗したテストがあれば、その内容も一緒に出力されるので、次の実行を待たずに修正作業に取り掛かることができます。

この機能は、ハングアップして動かなくなるテストのデバッグにも非常に便利です。Ctrl-T を押せば、どのテストが実行を試みているのかが分かるので、そのテストだけを切り出して原因を調査できます。

また私自身は、テストの完了に明らかに時間がかかっている(1秒以上など)ときには必ず Ctrl-T を押す習慣をつけました。おかげで、「もっと高速化すべき遅いテスト」を数多く発見できています。

Ctrl-Tはどうやって動いているのか?

Macでは、Ctrl-T を押すと、実行中のプログラムに対して INFO という名前のメッセージ(シグナル)が送られます。

puts "Starting..."
trap("INFO") { puts "INFO triggered!" }

loop { print "."; sleep 0.1}

~/Source jweiss$ ruby signal_test.rb
Starting...
........^Tload: 7.14  cmd: ruby 6121 running 0.10u 0.08s
INFO triggered!
.......^Tload: 7.14  cmd: ruby 6121 running 0.10u 0.08s
INFO triggered!
................^Tload: 11.77  cmd: ruby 6121 running 0.10u 0.08s
.INFO triggered!
......^Csignal_test.rb:5:in `sleep': Interrupt
	from signal_test.rb:5:in `block in <main>'
	from signal_test.rb:5:in `loop'
	from signal_test.rb:5:in `<main>'

Minitestはこの INFO シグナルを認識しており、受け取るとテスト実行に関する情報を出力します。

~/Source/rails/activesupport[master] jweiss$ be rake
/usr/local/Cellar/ruby/2.2.0/bin/ruby -w -I"lib:test"  "/usr/local/Cellar/ruby/2.2.0/lib/ruby/2.2.0/rake/rake_test_loader.rb" "test/**/*_test.rb" 
Run options: --seed 33445

# Running:

.................F........^Tload: 1.62  cmd: ruby 29646 running 4.37u 1.40s
Current results:


  1) Failure:
CleanLoggerTest#test_format_message [/Users/jweiss/Source/rails/activesupport/test/clean_logger_test.rb:13]:
Expected "error\n" to not be equal to "error\n".



Current: DigestUUIDExt#test_invalid_hash_class 0.02s
............................

なかなか便利ですよね。

この仕組みを知ると、「他のアプリでも INFO を活用できるのでは?」とアイデアが浮かぶかもしれません。

• Railsなら、現在実行中のコントローラアクションやパフォーマンス統計を表示できるでしょう。
• Sidekiqなら、各ワーカーが何を処理しているのかを表示できれば、どこで詰まっているのか一目瞭然になります。

実際、Sidekiqはかつて INFO を使って、実行中の各スレッドのバックトレースを出力していました。しかし INFO はLinuxではサポートされていないため、Sidekiqは別のシグナルへ移行しました。残念ながら、その代替シグナルは INFO のようにキーボードショートカットで送信することができません。

INFO がLinuxで使えないこと(そして、この用途での INFO の使い方は厳密には正しくないと指摘する人もいること)から、この挙動は本来あるべきほど広まっていません。

とはいえ、さまざまな場面で役立つちょっとした助けになるのは間違いありません。 アプリケーションを開発しているなら、興味を持ったユーザーのために、どんなステータス情報をオンデマンドで表示できるか考えてみる価値があるでしょう。