CircleCIでdotnet test、妙な挙動をすることは前回1つ紹介しました。
が、まさかまた1つネタが見つかるとは思わなかったです。
今回はdotnet testがこけた時の出力について。
更新
2020/6/17本件の修正がマージされて修正されました。やったね。
概要
dotnet testに< /dev/nullを付けると出力も正常になる
まさかのこれと同じ対策で解消します。
問題
問題は2つあります。
- CircleCI上で
dotnet testをしたときに、verbosityがquietとして実行される。(dotnet testのデフォルトverbosityはminimal) - CircleCI上で
dotnet testのConsole Loggerのverbosityをオーバーライド指定して実行してもquietから変わらない
dotnet test のおさらい
問題を把握するためには、dotnet testの基本的な挙動を把握しておく必要があります。
ざっくり説明します。
ローカルで適当にxUnitのプロジェクトを作って、適当に失敗するFactを作りdotnet testで実行すると、テストの失敗個所が表示されます。
このテストの失敗個所が表示されるのは、verbosityレベルがminimal以上の時で、dotnet testはデフォルトでminimalに設定されています。
$ dotnet test
Test run for C:\git\guitarrapc\dotnet-test-lab\tests\XUnitTestProject1\bin\Debug\netcoreapp3.1\XUnitTestProject1.dll(.NETCoreApp,Version=v3.1)
Microsoft (R) Test Execution Command Line Tool Version 16.3.0
Copyright (c) Microsoft Corporation. All rights reserved.
Starting test execution, please wait...
A total of 1 test files matched the specified pattern.
[xUnit.net 00:00:01.61] XUnitTestProject1.UnitTest1.BoolFailTest [FAIL]
X XUnitTestProject1.UnitTest1.BoolFailTest [7ms]
Error Message:
Assert.False() Failure
Expected: False
Actual: True
Stack Trace:
at XUnitTestProject1.UnitTest1.BoolFailTest() in C:\git\guitarrapc\dotnet-test-lab\tests\XUnitTestProject1\UnitTest1.cs:line 33
Test Run Failed.
Total tests: 4
Passed: 3
Failed: 1
Total time: 2.9317 Seconds
この結果の解像度をオーバーライドすることは、dotnet test自体、あるいはTest Loggerごとに設定可能です。
dotnet test自体のverbosityをオーバーライドするなら--verbosity引数を使ってdotnet test --verbosity [quiet|minimal|normal|detailed]を指定dotnet testの特定のテストロガーをオーバーライドするなら--logger:ロガー名;verbosity=[quiet|minimal|normal|detailed]を指定
dotnet test自体のverbosityを上げると、ビルドログなど見たくないログも増えてしまうのであまり好みじゃないです。
そのため通常は、Consoleロガーのverbosityだけ挙げて対処するでしょう。
たとえばConsoleLoggerのverbosityをnormalにするならこのように指定します。
normalにしてお手元で実行すると、今までdotnet testで出力されていなかった1つ1つのテストが成功、失敗にかかわらず出力されるはずです。
dotnet test "--logger:Console;verbosity=normal"
このことから、押さえておくべきは2つです。
dotnet testをverbosity指定なしに実行したときはminimalを期待している- もし
verbosityがちがった場合でも、--logger:console;verbosity=minimalなどでオバーライドできることを期待している
何が問題なのか
CircleCI上でローカルと同じようにdotnet testを実行すると、失敗したテストの詳細が表示されないことに気がつきます。
これはverbosityがquietの時の表示と合致し、ローカルでもdotnet test --verbosity quietとすると再現します。
つまり、指定していないのになぜかverbosityがminimalではなくquietになっています。
$ dotnet test -c Debug Test run for /root/project/tests/XUnitTestProject1/bin/Debug/netcoreapp3.1/XUnitTestProject1.dll(.NETCoreApp,Version=v3.1) VSTest: Starting vstest.console... VSTest: Arguments: dotnet exec /usr/share/dotnet/sdk/3.1.100/vstest.console.dll --testAdapterPath:/root/.nuget/packages/coverlet.collector/1.2.0/build/netstandard1.0/ --framework:.NETCoreApp,Version=v3.1 --logger:Console;verbosity=minimal --Diag:/root/project/bin/default/log.txt /root/project/tests/XUnitTestProject1/bin/Debug/netcoreapp3.1/XUnitTestProject1.dll Microsoft (R) Test Execution Command Line Tool Version 16.3.0 Copyright (c) Microsoft Corporation. All rights reserved. Starting test execution, please wait... A total of 1 test files matched the specified pattern. [xUnit.net 00:00:00.49] XUnitTestProject1.UnitTest1.BoolFailTest [FAIL] Test run in progress.VSTest: Exit code: 1 Exited with code exit status 1
また、このverbosityをオーバーライドしようとしてもminimalから変更されずquiet時の出力のままです。
#!/bin/bash -eo pipefail dotnet test -c Debug "--logger:Console;verbosity=minimal" Test run for /root/project/tests/XUnitTestProject1/bin/Debug/netcoreapp3.1/XUnitTestProject1.dll(.NETCoreApp,Version=v3.1) VSTest: Starting vstest.console... VSTest: Arguments: dotnet exec /usr/share/dotnet/sdk/3.1.100/vstest.console.dll --testAdapterPath:/root/.nuget/packages/coverlet.collector/1.2.0/build/netstandard1.0/ --framework:.NETCoreApp,Version=v3.1 --logger:Console;verbosity=minimal --Diag:/root/project/bin/default/log.txt /root/project/tests/XUnitTestProject1/bin/Debug/netcoreapp3.1/XUnitTestProject1.dll Microsoft (R) Test Execution Command Line Tool Version 16.3.0 Copyright (c) Microsoft Corporation. All rights reserved. Starting test execution, please wait... A total of 1 test files matched the specified pattern. [xUnit.net 00:00:00.49] XUnitTestProject1.UnitTest1.BoolFailTest [FAIL] Test run in progress.VSTest: Exit code: 1 Exited with code exit status 1
これはもちろん、dotnet test -c Debug --verbosity=minimalでも変わらずquietのままです。
再現リポジトリ
再現リポジトリを組んであります。
ワークアラウンド
dotnet testに< /dev/nullを付けると、dotnet testのデフォルトverbosityがminimalに正常化されます。
また、verbosityのオーバーライドも正常に機能するようになります。
進捗
microsoft/vstestに報告してあるので、根本対処されるかはIssueの結果次第です。
まとめ
英語含めて記事が全然ないところみると、.NETでCircleCIやはり利用少ない気配があります。
前ならAzure Pipeline、今ならGitHub Actionsを使う人が多くなっていくんだろうなぁと感じます。 これはMicrosoftのdocsなどでの露出に誘導されてるのも多分にあるんですかね? と思ったり思わなかったり。
余談: 調査する
当初、CircleCIではなくUbuntuか環境問題? と思ったのですが、ローカルでdotnet testしたり、Docker上でCircleCIと同じdotnet-sdk:3.1イメージを使ってテストを実行しても再現せず正常に指定したverbosityでオーバーライドができます。
この時点で環境問題の可能性は消えます。Dockerさいこー。
コードを確認すると、--Logger:"Console;verbosity=minimal"を渡せば解釈されることがわかります。
var verbosityExists = parameters.TryGetValue(ConsoleLogger.VerbosityParam, out string verbosity); if (verbosityExists && Enum.TryParse(verbosity, true, out Verbosity verbosityLevel)) { this.verbosityLevel = verbosityLevel; }
vstest/ConsoleLogger.cs at 5ef1f3b60404588b91fabb4fab22304ac88b108a · microsoft/vstest
他に何か原因があるのかといろいろ調べたけど、ことごとく該当せず...。
- dotnet test コマンド - .NET Core CLI | Microsoft Docs
- .NET Core tests produce no output · Issue #1141 · xunit/xunit
- c# - Xunit Unit Tests will not run - Stack Overflow
- dotnet test verbosity level for test output only · Issue #1773 · microsoft/vstest
- Make --verbosity case insensitive by nohwnd · Pull Request #2300 · microsoft/vstest
- Tests hang from dotnet test · Issue #2080 · microsoft/vstest
そういえば自分のプロジェクトで、この問題が出ず正常にできているものがあるのでなぜかを見てみると、まさかの< /dev/nullをしていて前のIssueと同じ対処で解決できています。
ということで、原因はよくわからないけど< /dev/nullで出力まで改善されるという謎結果に...。
なお、Diagnostics Logを--diag:diag.txtで出してみてみると、<dev/nullを指定しなくてもちゃんとverbosityが設定した値になっているので、 < /dev/nullで治るのはmake senseといえばそうですが謎い。
しかし、なんで/dev/nullで出力というか挙動が変わるんだ.... stdinなんて何か色ない限りhandleしないと考えたんだけど....?
